espressif / esp-idf

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

No boot error with: memory_layout: SOC_RESERVE_MEMORY_REGION region range 0xfffffffc - 0x00000000 ov (IDFGH-403) #2561

Closed X-Ryl669 closed 1 year ago

X-Ryl669 commented 6 years ago

Environment

Problem Description

Suddenly, my app does not boot anymore. I've reverted my changes and it still does not boot up. I get this output:

I (186) boot: ESP-IDF v3.2-dev-915-g6f58208 2nd stage bootloader
I (187) boot: compile time 07:12:15
I (187) boot: Enabling RNG early entropy source...
I (207) boot: SPI Speed      : 40MHz
I (220) boot: SPI Mode       : DIO
I (233) boot: SPI Flash Size : 4MB
I (246) boot: Partition Table:
I (257) boot: ## Label            Usage          Type ST Offset   Length
I (279) boot:  0 nvs              WiFi data        01 02 00009000 00004000
I (303) boot:  1 otadata          OTA data         01 00 0000d000 00002000
I (326) boot:  2 phy_init         RF data          01 01 0000f000 00001000
I (349) boot:  3 factory          factory app      00 00 00010000 000f0000
I (372) boot:  4 ota_0            OTA app          00 10 00100000 00100000
I (396) boot:  5 ota_1            OTA app          00 11 00200000 00100000
I (419) boot:  6 storage          Unknown data     01 82 00300000 00100000
I (443) boot: End of partition table
I (456) boot: Defaulting to factory image
I (470) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x1fffc (131068) map
I (773) esp_image: segment 1: paddr=0x00030024 vaddr=0x3ffbdb60 size=0x031ac ( 12716) load
I (803) esp_image: segment 2: paddr=0x000331d8 vaddr=0x3ffc0d0c size=0x00000 (     0) load
I (805) esp_image: segment 3: paddr=0x000331e0 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

I (831) esp_image: segment 4: paddr=0x000335e8 vaddr=0x40080400 size=0x0ca28 ( 51752) load
I (981) esp_image: segment 5: paddr=0x00040018 vaddr=0x400d0018 size=0x82868 (534632) map
0x400d0018: _stext at ??:?

I (2103) esp_image: segment 6: paddr=0x000c2888 vaddr=0x4008ce28 size=0x02e00 ( 11776) load
0x4008ce28: vPortYield at /Users/cyril/esp/esp-idf/components/freertos/portasm.S:528

I (2133) esp_image: segment 7: paddr=0x000c5690 vaddr=0x400c0000 size=0x00000 (     0) load
I (2135) esp_image: segment 8: paddr=0x000c5698 vaddr=0x50000200 size=0x00000 (     0) load
I (2217) boot: Loaded app from partition at offset 0x10000
I (2217) boot: Disabling RNG early entropy source...
I (2221) cpu_start: Pro cpu up.
I (2230) cpu_start: Starting app cpu, entry point is 0x40081028
0x40081028: call_start_cpu1 at /Users/cyril/esp/esp-idf/components/esp32/cpu_start.c:228

I (1) cpu_start: App cpu up.
E (2263) memory_layout: SOC_RESERVE_MEMORY_REGION region range 0xfffffffc - 0x00000000 overlaps with 0xffffffff - 0xffffffff
abort() was called at PC 0x401157cb on core 0
0x401157cb: s_prepare_reserved_regions at /Users/cyril/esp/esp-idf/components/soc/src/memory_layout_utils.c:97
 (inlined by) soc_get_available_memory_regions at /Users/cyril/esp/esp-idf/components/soc/src/memory_layout_utils.c:114

Backtrace: 0x4008db47:0x3ffe3550 0x4008ddb9:0x3ffe3570 0x401157cb:0x3ffe3590 0x400d2b11:0x3ffe38e0 0x40081192:0x3ffe3c60 0x400790f5:0x3ffe3c80 0x400794c9:0x3ffe3cc0 0x400807e6:0x3ffe3df0 0x40007c31:0x3ffe3eb0 0x4000073d:0x3ffe3f20
0x4008db47: invoke_abort at /Users/cyril/esp/esp-idf/components/esp32/panic.c:660

0x4008ddb9: abort at /Users/cyril/esp/esp-idf/components/esp32/panic.c:660

0x401157cb: s_prepare_reserved_regions at /Users/cyril/esp/esp-idf/components/soc/src/memory_layout_utils.c:97
 (inlined by) soc_get_available_memory_regions at /Users/cyril/esp/esp-idf/components/soc/src/memory_layout_utils.c:114

0x400d2b11: heap_caps_init at /Users/cyril/esp/esp-idf/components/heap/heap_caps_init.c:65

0x40081192: call_start_cpu0 at /Users/cyril/esp/esp-idf/components/esp32/cpu_start.c:213

Looking at the code, I'm seeing this:

if (reserved[i].end > reserved[i+1].start) {
                ESP_EARLY_LOGE(TAG, "SOC_RESERVE_MEMORY_REGION region range " \
                               "0x%08x - 0x%08x overlaps with 0x%08x - 0x%08x",
                               reserved[i].start, reserved[i].end, reserved[i+1].start,
                               reserved[i+1].end);
                abort();
}

Since both reserved[i].end and start are int_ptr, the test above fails while end is 0 and (start is 0xFF.... thus negative).

The system does not boot. Please notice that the application size fits the partition (partition is 900kB or so, while the app is 740kB), and make size returns:

Total sizes:
 DRAM .data size:   12716 bytes
 DRAM .bss  size:   94848 bytes
Used static DRAM:  107564 bytes (  17016 available, 86.3% used)
Used static IRAM:   64552 bytes (  66520 available, 49.2% used)
      Flash code:  534630 bytes
    Flash rodata:  131068 bytes
Total image size:~ 742966 bytes (.bin may be padded larger)

Expected Behavior

The application should start

Actual Behavior

It does not (the CPU 0 does not start)

Steps to repropduce

I've no idea why this appeared suddenly. I've reverted my changes, make clean and make, yet it's still there (while it worked perfectly before).

Other items if possible

igrr commented 6 years ago

Could you please set application log level to verbose (in menuconfig, component config, log output), and attach the output you get?

On Sun, Oct 14, 2018, 17:30 X-Ryl669 notifications@github.com wrote:

Environment

  • Development Kit: [ESP32-Wrover-Kit]
  • Kit version (for WroverKit/PicoKit/DevKitC): [?]
  • Core (if using chip or module): []
  • IDF version (git rev-parse --short HEAD to get the commit id.): 9ca30f6
  • Development Env: [Make]
  • Operating System: [MacOS]
  • Power Supply: [USB]

Problem Description

Suddenly, my app does not boot anymore. I've reverted my changes and it still does not boot up. I get this output:

I (186) boot: ESP-IDF v3.2-dev-915-g6f58208 2nd stage bootloader I (187) boot: compile time 07:12:15 I (187) boot: Enabling RNG early entropy source... I (207) boot: SPI Speed : 40MHz I (220) boot: SPI Mode : DIO I (233) boot: SPI Flash Size : 4MB I (246) boot: Partition Table: I (257) boot: ## Label Usage Type ST Offset Length I (279) boot: 0 nvs WiFi data 01 02 00009000 00004000 I (303) boot: 1 otadata OTA data 01 00 0000d000 00002000 I (326) boot: 2 phy_init RF data 01 01 0000f000 00001000 I (349) boot: 3 factory factory app 00 00 00010000 000f0000 I (372) boot: 4 ota_0 OTA app 00 10 00100000 00100000 I (396) boot: 5 ota_1 OTA app 00 11 00200000 00100000 I (419) boot: 6 storage Unknown data 01 82 00300000 00100000 I (443) boot: End of partition table I (456) boot: Defaulting to factory image I (470) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x1fffc (131068) map I (773) esp_image: segment 1: paddr=0x00030024 vaddr=0x3ffbdb60 size=0x031ac ( 12716) load I (803) esp_image: segment 2: paddr=0x000331d8 vaddr=0x3ffc0d0c size=0x00000 ( 0) load I (805) esp_image: segment 3: paddr=0x000331e0 vaddr=0x40080000 size=0x00400 ( 1024) load 0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

I (831) esp_image: segment 4: paddr=0x000335e8 vaddr=0x40080400 size=0x0ca28 ( 51752) load I (981) esp_image: segment 5: paddr=0x00040018 vaddr=0x400d0018 size=0x82868 (534632) map 0x400d0018: _stext at ??:?

I (2103) esp_image: segment 6: paddr=0x000c2888 vaddr=0x4008ce28 size=0x02e00 ( 11776) load 0x4008ce28: vPortYield at /Users/cyril/esp/esp-idf/components/freertos/portasm.S:528

I (2133) esp_image: segment 7: paddr=0x000c5690 vaddr=0x400c0000 size=0x00000 ( 0) load I (2135) esp_image: segment 8: paddr=0x000c5698 vaddr=0x50000200 size=0x00000 ( 0) load I (2217) boot: Loaded app from partition at offset 0x10000 I (2217) boot: Disabling RNG early entropy source... I (2221) cpu_start: Pro cpu up. I (2230) cpu_start: Starting app cpu, entry point is 0x40081028 0x40081028: call_start_cpu1 at /Users/cyril/esp/esp-idf/components/esp32/cpu_start.c:228

I (1) cpu_start: App cpu up. E (2263) memory_layout: SOC_RESERVE_MEMORY_REGION region range 0xfffffffc - 0x00000000 overlaps with 0xffffffff - 0xffffffff abort() was called at PC 0x401157cb on core 0 0x401157cb: s_prepare_reserved_regions at /Users/cyril/esp/esp-idf/components/soc/src/memory_layout_utils.c:97 (inlined by) soc_get_available_memory_regions at /Users/cyril/esp/esp-idf/components/soc/src/memory_layout_utils.c:114

Backtrace: 0x4008db47:0x3ffe3550 0x4008ddb9:0x3ffe3570 0x401157cb:0x3ffe3590 0x400d2b11:0x3ffe38e0 0x40081192:0x3ffe3c60 0x400790f5:0x3ffe3c80 0x400794c9:0x3ffe3cc0 0x400807e6:0x3ffe3df0 0x40007c31:0x3ffe3eb0 0x4000073d:0x3ffe3f20 0x4008db47: invoke_abort at /Users/cyril/esp/esp-idf/components/esp32/panic.c:660

0x4008ddb9: abort at /Users/cyril/esp/esp-idf/components/esp32/panic.c:660

0x401157cb: s_prepare_reserved_regions at /Users/cyril/esp/esp-idf/components/soc/src/memory_layout_utils.c:97 (inlined by) soc_get_available_memory_regions at /Users/cyril/esp/esp-idf/components/soc/src/memory_layout_utils.c:114

0x400d2b11: heap_caps_init at /Users/cyril/esp/esp-idf/components/heap/heap_caps_init.c:65

0x40081192: call_start_cpu0 at /Users/cyril/esp/esp-idf/components/esp32/cpu_start.c:213

Looking at the code, I'm seeing this:

if (reserved[i].end > reserved[i+1].start) { ESP_EARLY_LOGE(TAG, "SOC_RESERVE_MEMORY_REGION region range " \ "0x%08x - 0x%08x overlaps with 0x%08x - 0x%08x", reserved[i].start, reserved[i].end, reserved[i+1].start, reserved[i+1].end); abort(); }

Since both reserved[i].end and start are int_ptr, the test above fails while end is 0 and (start is 0xFF.... thus negative).

The system does not boot. Please notice that the application size fits the partition (partition is 900kB or so, while the app is 740kB), and make size returns:

Total sizes: DRAM .data size: 12716 bytes DRAM .bss size: 94848 bytes Used static DRAM: 107564 bytes ( 17016 available, 86.3% used) Used static IRAM: 64552 bytes ( 66520 available, 49.2% used) Flash code: 534630 bytes Flash rodata: 131068 bytes Total image size:~ 742966 bytes (.bin may be padded larger)

Expected Behavior

The application should start Actual Behavior

It does not (the CPU 0 does not start) Steps to repropduce

I've no idea why this appeared suddenly. I've reverted my changes, make clean and make, yet it's still there (while it worked perfectly before). Other items if possible

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/espressif/esp-idf/issues/2561, or mute the thread https://github.com/notifications/unsubscribe-auth/AEJcesAtposWvveLFntkAD6b1Y-OaSUqks5ukxIzgaJpZM4XbD85 .

X-Ryl669 commented 6 years ago

Very strange... With log set to verbose, the application boots Anyway, here are the logs:

I (187) boot: ESP-IDF v3.2-dev-915-g6f58208 2nd stage bootloader
I (187) boot: compile time 07:12:15
I (188) boot: Enabling RNG early entropy source...
I (208) boot: SPI Speed      : 40MHz
I (221) boot: SPI Mode       : DIO
I (233) boot: SPI Flash Size : 4MB
I (247) boot: Partition Table:
I (257) boot: ## Label            Usage          Type ST Offset   Length
I (280) boot:  0 nvs              WiFi data        01 02 00009000 00004000
I (303) boot:  1 otadata          OTA data         01 00 0000d000 00002000
I (327) boot:  2 phy_init         RF data          01 01 0000f000 00001000
I (350) boot:  3 factory          factory app      00 00 00010000 000f0000
I (373) boot:  4 ota_0            OTA app          00 10 00100000 00100000
I (396) boot:  5 ota_1            OTA app          00 11 00200000 00100000
I (419) boot:  6 storage          Unknown data     01 82 00300000 00100000
I (443) boot: End of partition table
I (456) boot: Defaulting to factory image
I (470) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x25424 (152612) map
I (819) esp_image: segment 1: paddr=0x0003544c vaddr=0x3ffbdb60 size=0x031ac ( 12716) load
I (849) esp_image: segment 2: paddr=0x00038600 vaddr=0x3ffc0d0c size=0x00000 (     0) load
I (851) esp_image: segment 3: paddr=0x00038608 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

I (876) esp_image: segment 4: paddr=0x00038a10 vaddr=0x40080400 size=0x07600 ( 30208) load
I (975) esp_image: segment 5: paddr=0x00040018 vaddr=0x400d0018 size=0x85b38 (547640) map
0x400d0018: _stext at ??:?

I (2123) esp_image: segment 6: paddr=0x000c5b58 vaddr=0x40087a00 size=0x0824c ( 33356) load
0x40087a00: rcUpdateTxDoneAmpdu2 at ??:?

I (2206) esp_image: segment 7: paddr=0x000cddac vaddr=0x400c0000 size=0x00000 (     0) load
I (2208) esp_image: segment 8: paddr=0x000cddb4 vaddr=0x50000200 size=0x00000 (     0) load
I (2286) boot: Loaded app from partition at offset 0x10000
I (2286) boot: Disabling RNG early entropy source...
I (2290) cpu_start: Pro cpu up.
I (2299) cpu_start: Starting app cpu, entry point is 0x40081030
0x40081030: call_start_cpu1 at /Users/cyril/esp/esp-idf/components/esp32/cpu_start.c:228

I (1) cpu_start: App cpu up.
V (2331) memory_layout: reserved range is 0x3f42541c - 0x3f425444
D (2349) memory_layout: Checking 7 reserved memory ranges:
D (2366) memory_layout: Reserved memory range 0x3ffae000 - 0x3ffae6e0
D (2387) memory_layout: Reserved memory range 0x3ffbdb60 - 0x3ffd7fc8
D (2407) memory_layout: Reserved memory range 0x3ffe0000 - 0x3ffe0440
D (2427) memory_layout: Reserved memory range 0x3ffe4000 - 0x3ffe4350
D (2447) memory_layout: Reserved memory range 0x40070000 - 0x40078000
D (2467) memory_layout: Reserved memory range 0x40078000 - 0x40080000
0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

D (2487) memory_layout: Reserved memory range 0x40080000 - 0x4008fc4c
0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

D (2507) memory_layout: Building list of available memory regions:
V (2526) memory_layout: Examining memory region 0x3ffae000 - 0x3ffb0000
V (2547) memory_layout: Start of region 0x3ffae000 - 0x3ffb0000 overlaps reserved 0x3ffae000 - 0x3ffae6e0
D (2576) memory_layout: Available memory region 0x3ffae6e0 - 0x3ffb0000
V (2597) memory_layout: Examining memory region 0x3ffb0000 - 0x3ffb8000
D (2617) memory_layout: Available memory region 0x3ffb0000 - 0x3ffb8000
V (2638) memory_layout: Examining memory region 0x3ffb8000 - 0x3ffc0000
V (2658) memory_layout: End of region 0x3ffb8000 - 0x3ffc0000 overlaps reserved 0x3ffbdb60 - 0x3ffd7fc8
D (2687) memory_layout: Available memory region 0x3ffb8000 - 0x3ffbdb60
V (2708) memory_layout: Examining memory region 0x3ffc0000 - 0x3ffc2000
V (2729) memory_layout: Region 0x3ffc0000 - 0x3ffc2000 inside of reserved 0x3ffbdb60 - 0x3ffd7fc8
V (2756) memory_layout: Examining memory region 0x3ffc2000 - 0x3ffc4000
V (2777) memory_layout: Region 0x3ffc2000 - 0x3ffc4000 inside of reserved 0x3ffbdb60 - 0x3ffd7fc8
V (2804) memory_layout: Examining memory region 0x3ffc4000 - 0x3ffc6000
V (2825) memory_layout: Region 0x3ffc4000 - 0x3ffc6000 inside of reserved 0x3ffbdb60 - 0x3ffd7fc8
V (2852) memory_layout: Examining memory region 0x3ffc6000 - 0x3ffc8000
V (2873) memory_layout: Region 0x3ffc6000 - 0x3ffc8000 inside of reserved 0x3ffbdb60 - 0x3ffd7fc8
V (2900) memory_layout: Examining memory region 0x3ffc8000 - 0x3ffca000
V (2921) memory_layout: Region 0x3ffc8000 - 0x3ffca000 inside of reserved 0x3ffbdb60 - 0x3ffd7fc8
V (2948) memory_layout: Examining memory region 0x3ffca000 - 0x3ffcc000
V (2969) memory_layout: Region 0x3ffca000 - 0x3ffcc000 inside of reserved 0x3ffbdb60 - 0x3ffd7fc8
V (2996) memory_layout: Examining memory region 0x3ffcc000 - 0x3ffce000
V (3017) memory_layout: Region 0x3ffcc000 - 0x3ffce000 inside of reserved 0x3ffbdb60 - 0x3ffd7fc8
V (3045) memory_layout: Examining memory region 0x3ffce000 - 0x3ffd0000
V (3065) memory_layout: Region 0x3ffce000 - 0x3ffd0000 inside of reserved 0x3ffbdb60 - 0x3ffd7fc8
V (3093) memory_layout: Examining memory region 0x3ffd0000 - 0x3ffd2000
V (3113) memory_layout: Region 0x3ffd0000 - 0x3ffd2000 inside of reserved 0x3ffbdb60 - 0x3ffd7fc8
V (3141) memory_layout: Examining memory region 0x3ffd2000 - 0x3ffd4000
V (3161) memory_layout: Region 0x3ffd2000 - 0x3ffd4000 inside of reserved 0x3ffbdb60 - 0x3ffd7fc8
V (3189) memory_layout: Examining memory region 0x3ffd4000 - 0x3ffd6000
V (3209) memory_layout: Region 0x3ffd4000 - 0x3ffd6000 inside of reserved 0x3ffbdb60 - 0x3ffd7fc8
V (3237) memory_layout: Examining memory region 0x3ffd6000 - 0x3ffd8000
V (3257) memory_layout: Start of region 0x3ffd6000 - 0x3ffd8000 overlaps reserved 0x3ffbdb60 - 0x3ffd7fc8
D (3287) memory_layout: Available memory region 0x3ffd7fc8 - 0x3ffd8000
V (3308) memory_layout: Examining memory region 0x3ffd8000 - 0x3ffda000
D (3328) memory_layout: Available memory region 0x3ffd8000 - 0x3ffda000
V (3349) memory_layout: Examining memory region 0x3ffda000 - 0x3ffdc000
D (3369) memory_layout: Available memory region 0x3ffda000 - 0x3ffdc000
V (3390) memory_layout: Examining memory region 0x3ffdc000 - 0x3ffde000
D (3410) memory_layout: Available memory region 0x3ffdc000 - 0x3ffde000
V (3431) memory_layout: Examining memory region 0x3ffde000 - 0x3ffe0000
D (3452) memory_layout: Available memory region 0x3ffde000 - 0x3ffe0000
V (3472) memory_layout: Examining memory region 0x3ffe0000 - 0x3ffe4000
V (3493) memory_layout: Start of region 0x3ffe0000 - 0x3ffe4000 overlaps reserved 0x3ffe0000 - 0x3ffe0440
D (3522) memory_layout: Available memory region 0x3ffe0440 - 0x3ffe4000
V (3543) memory_layout: Examining memory region 0x3ffe4000 - 0x3ffe8000
V (3563) memory_layout: Start of region 0x3ffe4000 - 0x3ffe8000 overlaps reserved 0x3ffe4000 - 0x3ffe4350
D (3593) memory_layout: Available memory region 0x3ffe4350 - 0x3ffe8000
V (3614) memory_layout: Examining memory region 0x3ffe8000 - 0x3fff0000
D (3634) memory_layout: Available memory region 0x3ffe8000 - 0x3fff0000
V (3655) memory_layout: Examining memory region 0x3fff0000 - 0x3fff8000
D (3675) memory_layout: Available memory region 0x3fff0000 - 0x3fff8000
V (3696) memory_layout: Examining memory region 0x3fff8000 - 0x3fffc000
D (3716) memory_layout: Available memory region 0x3fff8000 - 0x3fffc000
V (3737) memory_layout: Examining memory region 0x3fffc000 - 0x40000000
D (3758) memory_layout: Available memory region 0x3fffc000 - 0x40000000
V (3778) memory_layout: Examining memory region 0x40070000 - 0x40078000
V (3799) memory_layout: Region 0x40070000 - 0x40078000 inside of reserved 0x40070000 - 0x40078000
V (3826) memory_layout: Examining memory region 0x40078000 - 0x40080000
0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

V (3847) memory_layout: Region 0x40078000 - 0x40080000 inside of reserved 0x40078000 - 0x40080000
0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

V (3874) memory_layout: Examining memory region 0x40080000 - 0x40082000
0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

0x40082000: esp_cpu_unstall at /Users/cyril/esp/esp-idf/components/soc/esp32/cpu_util.c:43

V (3895) memory_layout: Region 0x40080000 - 0x40082000 inside of reserved 0x40080000 - 0x4008fc4c
0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

0x40082000: esp_cpu_unstall at /Users/cyril/esp/esp-idf/components/soc/esp32/cpu_util.c:43

0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

V (3922) memory_layout: Examining memory region 0x40082000 - 0x40084000
0x40082000: esp_cpu_unstall at /Users/cyril/esp/esp-idf/components/soc/esp32/cpu_util.c:43

0x40084000: esp_reset_reason_get_hint at ??:?

V (3943) memory_layout: Region 0x40082000 - 0x40084000 inside of reserved 0x40080000 - 0x4008fc4c
0x40082000: esp_cpu_unstall at /Users/cyril/esp/esp-idf/components/soc/esp32/cpu_util.c:43

0x40084000: esp_reset_reason_get_hint at ??:?

0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

V (3970) memory_layout: Examining memory region 0x40084000 - 0x40086000
0x40084000: esp_reset_reason_get_hint at ??:?

0x40086000: ppCalTxAMPDULength at ??:?

V (3991) memory_layout: Region 0x40084000 - 0x40086000 inside of reserved 0x40080000 - 0x4008fc4c
0x40084000: esp_reset_reason_get_hint at ??:?

0x40086000: ppCalTxAMPDULength at ??:?

0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

V (4019) memory_layout: Examining memory region 0x40086000 - 0x40088000
0x40086000: ppCalTxAMPDULength at ??:?

0x40088000: wDev_ProcessTxop at ??:?

V (4039) memory_layout: Region 0x40086000 - 0x40088000 inside of reserved 0x40080000 - 0x4008fc4c
0x40086000: ppCalTxAMPDULength at ??:?

0x40088000: wDev_ProcessTxop at ??:?

0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

V (4067) memory_layout: Examining memory region 0x40088000 - 0x4008a000
0x40088000: wDev_ProcessTxop at ??:?

0x4008a000: set_chan_dig_gain at /home/cff/gittree/chip7.1_phy/chip_7.1/board_code/app_test/pp/phy/phy_chip_v7_cal.c:2458 (discriminator 1)

V (4087) memory_layout: Region 0x40088000 - 0x4008a000 inside of reserved 0x40080000 - 0x4008fc4c
0x40088000: wDev_ProcessTxop at ??:?

0x4008a000: set_chan_dig_gain at /home/cff/gittree/chip7.1_phy/chip_7.1/board_code/app_test/pp/phy/phy_chip_v7_cal.c:2458 (discriminator 1)

0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

V (4115) memory_layout: Examining memory region 0x4008a000 - 0x4008c000
0x4008a000: set_chan_dig_gain at /home/cff/gittree/chip7.1_phy/chip_7.1/board_code/app_test/pp/phy/phy_chip_v7_cal.c:2458 (discriminator 1)

0x4008c000: prvCheckTasksWaitingTermination at /Users/cyril/esp/esp-idf/components/freertos/tasks.c:3567
 (inlined by) prvIdleTask at /Users/cyril/esp/esp-idf/components/freertos/tasks.c:3391

V (4135) memory_layout: Region 0x4008a000 - 0x4008c000 inside of reserved 0x40080000 - 0x4008fc4c
0x4008a000: set_chan_dig_gain at /home/cff/gittree/chip7.1_phy/chip_7.1/board_code/app_test/pp/phy/phy_chip_v7_cal.c:2458 (discriminator 1)

0x4008c000: prvCheckTasksWaitingTermination at /Users/cyril/esp/esp-idf/components/freertos/tasks.c:3567
 (inlined by) prvIdleTask at /Users/cyril/esp/esp-idf/components/freertos/tasks.c:3391

0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

V (4163) memory_layout: Examining memory region 0x4008c000 - 0x4008e000
0x4008c000: prvCheckTasksWaitingTermination at /Users/cyril/esp/esp-idf/components/freertos/tasks.c:3567
 (inlined by) prvIdleTask at /Users/cyril/esp/esp-idf/components/freertos/tasks.c:3391

0x4008e000: setFirstBreakpoint at /Users/cyril/esp/esp-idf/components/esp32/panic.c:202

V (4183) memory_layout: Region 0x4008c000 - 0x4008e000 inside of reserved 0x40080000 - 0x4008fc4c
0x4008c000: prvCheckTasksWaitingTermination at /Users/cyril/esp/esp-idf/components/freertos/tasks.c:3567
 (inlined by) prvIdleTask at /Users/cyril/esp/esp-idf/components/freertos/tasks.c:3391

0x4008e000: setFirstBreakpoint at /Users/cyril/esp/esp-idf/components/esp32/panic.c:202

0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

V (4211) memory_layout: Examining memory region 0x4008e000 - 0x40090000
0x4008e000: setFirstBreakpoint at /Users/cyril/esp/esp-idf/components/esp32/panic.c:202

V (4231) memory_layout: Start of region 0x4008e000 - 0x40090000 overlaps reserved 0x40080000 - 0x4008fc4c
0x4008e000: setFirstBreakpoint at /Users/cyril/esp/esp-idf/components/esp32/panic.c:202

0x40080000: _WindowOverflow4 at /Users/cyril/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

D (4261) memory_layout: Available memory region 0x4008fc4c - 0x40090000
V (4282) memory_layout: Examining memory region 0x40090000 - 0x40092000
D (4302) memory_layout: Available memory region 0x40090000 - 0x40092000
V (4323) memory_layout: Examining memory region 0x40092000 - 0x40094000
D (4343) memory_layout: Available memory region 0x40092000 - 0x40094000
V (4364) memory_layout: Examining memory region 0x40094000 - 0x40096000
D (4384) memory_layout: Available memory region 0x40094000 - 0x40096000
V (4405) memory_layout: Examining memory region 0x40096000 - 0x40098000
D (4426) memory_layout: Available memory region 0x40096000 - 0x40098000
V (4446) memory_layout: Examining memory region 0x40098000 - 0x4009a000
D (4467) memory_layout: Available memory region 0x40098000 - 0x4009a000
V (4487) memory_layout: Examining memory region 0x4009a000 - 0x4009c000
D (4508) memory_layout: Available memory region 0x4009a000 - 0x4009c000
V (4528) memory_layout: Examining memory region 0x4009c000 - 0x4009e000
D (4549) memory_layout: Available memory region 0x4009c000 - 0x4009e000
V (4569) memory_layout: Examining memory region 0x4009e000 - 0x400a0000
D (4590) memory_layout: Available memory region 0x4009e000 - 0x400a0000
I (4611) heap_init: Initializing. RAM available for dynamic allocation:
D (4633) heap_init: New heap initialised at 0x3ffae6e0
I (4649) heap_init: At 3FFAE6E0 len 0000F480 (61 KiB): DRAM
D (4668) heap_init: New heap initialised at 0x3ffd7fc8
I (4684) heap_init: At 3FFD7FC8 len 00008038 (32 KiB): DRAM
I (4704) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (4723) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
D (4743) heap_init: New heap initialised at 0x4008fc4c
I (4759) heap_init: At 4008FC4C len 000103B4 (64 KiB): IRAM
I (4779) cpu_start: Pro cpu start user code
D (4814) clk: RTC_SLOW_CLK calibration value: 3242880
V (232) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (232) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (237) intr_alloc: Connected src 46 to int 2 (cpu 0)
V (243) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (249) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xC0E
D (257) intr_alloc: Connected src 57 to int 3 (cpu 0)
V (262) esp_dbg_stubs: esp_dbg_stubs_init stubs 3ffc1534
D (267) stack_chk: Intialize random stack guard
V (272) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (278) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
D (286) intr_alloc: Connected src 24 to int 9 (cpu 0)
I (291) cpu_start: Starting scheduler on PRO CPU.
V (0) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): checking args
V (0) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): Args okay. Resulting flags 0x40E
D (10) intr_alloc: Connected src 25 to int 2 (cpu 1)
I (10) cpu_start: Starting scheduler on APP CPU.
D (341) heap_init: New heap initialised at 0x3ffe0440
D (341) heap_init: New heap initialised at 0x3ffe4350
V (351) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (351) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (351) intr_alloc: Connected src 16 to int 12 (cpu 0)
I (371) gpio: GPIO[2]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
D (381) nvs: nvs_flash_init_custom partition=nvs start=9 count=4
D (421) nvs: nvs_open_from_partition nvse 1
Opened NVS correctly 0x1
D (421) nvs: nvs_open_from_partition misc 1
D (421) nvs: nvs_get_str_or_blob log
I (421) wifi: wifi driver task: 3ffb7150, prio:23, stack:3072, core=0
I (431) wifi: wifi firmware version: ece97c4
I (431) wifi: config NVS flash: enabled
I (441) wifi: config nano formating: enabled
I (441) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (451) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
D (461) nvs: nvs_open_from_partition nvs.net80211 1
D (461) nvs: nvs_get opmode 1
D (471) nvs: nvs_get_str_or_blob sta.ssid
D (471) nvs: nvs_get_str_or_blob sta.mac
D (481) nvs: nvs_get sta.authmode 1
D (481) nvs: nvs_get_str_or_blob sta.pswd
D (481) nvs: nvs_get_str_or_blob sta.pmk
D (491) nvs: nvs_get sta.chan 1
D (491) nvs: nvs_get auto.conn 1
D (491) nvs: nvs_get bssid.set 1
D (501) nvs: nvs_get_str_or_blob sta.bssid
D (501) nvs: nvs_get sta.lis_intval 2
D (511) nvs: nvs_get sta.phym 1
D (511) nvs: nvs_get sta.phybw 1
D (511) nvs: nvs_get_str_or_blob sta.apsw
D (521) nvs: nvs_get_str_or_blob sta.apinfo
D (521) nvs: nvs_get sta.scan_method 1
D (521) nvs: nvs_get sta.sort_method 1
D (531) nvs: nvs_get sta.minrssi 1
D (531) nvs: nvs_get sta.minauth 1
D (531) nvs: nvs_get_str_or_blob ap.ssid
D (541) nvs: nvs_get_str_or_blob ap.mac
D (541) nvs: nvs_get_str_or_blob ap.passwd
D (551) nvs: nvs_get_str_or_blob ap.pmk
D (551) nvs: nvs_get ap.chan 1
D (551) nvs: nvs_get ap.authmode 1
D (561) nvs: nvs_get ap.hidden 1
D (561) nvs: nvs_get ap.max.conn 1
D (561) nvs: nvs_get bcn.interval 2
D (571) nvs: nvs_get ap.phym 1
D (571) nvs: nvs_get ap.phybw 1
D (571) nvs: nvs_get ap.sndchan 1
D (581) nvs: nvs_get lorate 1
D (581) nvs: nvs_set_blob sta.mac 6
D (591) nvs: nvs_set_blob ap.mac 6
I (591) wifi: Init dynamic tx buffer num: 32
I (591) wifi: Init data frame dynamic rx buffer num: 32
I (601) wifi: Init management frame dynamic rx buffer num: 32
I (601) wifi: Init static rx buffer size: 1600
I (611) wifi: Init static rx buffer num: 10
I (611) wifi: Init dynamic rx buffer num: 32
WIFI started!
I (621) gpio: GPIO[22]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
D (621) nvs: nvs_get_str_or_blob bssid
D (631) nvs: nvs_get asStation 4
D (631) RTC_MODULE: Wi-Fi takes adc2 lock.
D (641) phy_init: loading PHY init data from application binary
D (641) nvs: nvs_open_from_partition phy 0
D (651) nvs: nvs_get cal_version 4
V (651) phy_init: phy_get_rf_cal_version: 3960

D (651) nvs: nvs_get_str_or_blob cal_mac
D (661) nvs: nvs_get_str_or_blob cal_data
D (671) nvs: nvs_close 4
I (721) phy: phy_version: 3960, 5211945, Jul 18 2018, 10:40:07, 0, 0
I (721) wifi: mode : sta (30:ae:a4:13:7e:e4) + softAP (30:ae:a4:13:7e:e5)
D (721) event: SYSTEM_EVENT_STA_START
V (721) event: enter default callback
V (731) tcpip_adapter: check: local, if=0 fn=0x4011dc1c
0x4011dc1c: tcpip_adapter_start_api at /Users/cyril/esp/esp-idf/components/tcpip_adapter/tcpip_adapter_lwip.c:1082

Started AP with name NVSE
X-Ryl669 commented 6 years ago

Reset the log to info works too. I'm not sure what happens.

projectgus commented 6 years ago

0xfffffffc - 0x00000000 overlaps with 0xffffffff - 0xffffffff

Given the number of 0xffs in here (the first two values are aligned to previous & next 4 byte boundaries, respectively, so it's likely the initial values of all 4 numbers were 0xffffffff), I think maybe you got a bad flash or a bad .bin file somehow? (0xff is the value of unwritten flash).

The values printed here should all have been linked into a special region of flash via the SOC_RESERVE_MEMORY_REGION() macro, and the addresses passed to that macro are always hard-coded to memory addresses in the 0x3ffff and 0x400 ranges.

Any chance that openocd was running when the errors occurred? If the JTAG debug port is active then verification of the app integrity on boot is skipped, to allow for software breakpoints to be inserted to flash.

X-Ryl669 commented 6 years ago

For bad flash, I don't think so. I've tried to erase the flash and reflash it and it did not report any error. About corrupted .bin, I've run a make clean; make twice. It's probably corrupted, but I can't figure out why. Notice that changing the sdkconfig did solve the issue, so you're probably right, but this means that some corrupted binary wasn't correctly cleaned and reused in the final bin, but the dependency on the sdkconfig was working correctly.

I'm not using OpenOCD (does not work great on a mac, at least last time I've checked). Only serial via USB was connected.

Since I don't understand much of this code area, I was wondering how I could understand better. Would a nm or objdump have helped show the (corrupted) sections address ? Is it possible the linker script is the culprit (I haven't modified it BTW) ? Is it dynamically generated ?

Also, the change that introduced the issue was the first usage of new in my code (everything before was using static allocation/bss and malloc when not possible).

projectgus commented 6 years ago

Hi @X-Ryl669,

Thanks for the extra details. In this case, I don't have any explanation for the behaviour.

The build system is tested in our CI system for correct behaviour around things like clean builds, so I don't expect it would fail to recompile sources, and especially to regenerate the .elf and .bin files after a make clean.

Parts of the linker script are dynamically generated based on config, but the part involved in SOC_RESERVE_MEMORY_REGION is not.

If the problem has become unreproducible then I'm not sure there's anything more we can do to investigate this for now.

If the problem re-occurs, please reopen the issue. If it's possible at that point to zip up the entire build directory (including the .bin and .elf files and all other intermediate files) and send it to us privately, this may help pin down the root cause.

X-Ryl669 commented 6 years ago

Ok, I'll let you know. Thanks!

ThomasRogg commented 5 years ago

We have the exact same problem within our product low.js for ESP32, with the exact same values:

I (524) cpu_start: Starting app cpu, entry point is 0x4008116c
0x4008116c: call_start_cpu1 at /Users/thomas/Documents/Beruflich/neonious/Development/neonious_one/esp-idf/components/esp32/cpu_start.c:252

I (516) cpu_start: App cpu up.
E (535) memory_layout: SOC_RESERVE_MEMORY_REGION region range 0xfffffffc - 0x00000000 overlaps with 0xffffffff - 0xffffffff
<restarts here>

The last commit we merged was 7efbe81 from Oct 29

For some reason some of the regions in the image are saved as 0xffffffff-0xffffffff. Seems like a linker or compiler bug. Most probably a linker bug, because it happens depending on how many string literals we have. Adding just one ESP_LOGE(TAG, "bla") => it works again.

Our work around:

    reserved[0].end = (intptr_t)&_bss_end;
    reserved[1].start = (intptr_t)&_iram_start; /* IRAM used by code */
    reserved[1].end = (intptr_t)&_iram_end;

+    // Hacking them inside here because of bug https://github.com/espressif/esp-idf/issues/2561
+    // Copied from soc_memory_layout
+    if(count != 8)
+    {
+        ESP_EARLY_LOGE(TAG, "not 8 mem regions!");
+        abort();
+    }
+    reserved[2].start = 0x40070000;
+    reserved[2].end = 0x40078000;
+    reserved[3].start = 0x40078000;
+    reserved[3].end = 0x40080000;
+    reserved[4].start = 0x3ffe0000;
+    reserved[4].end = 0x3ffe0440;
+    reserved[5].start = 0x3ffe4000;
+    reserved[5].end = 0x3ffe4350;
+    reserved[6].start = 0x3ffae000;
+    reserved[6].end = 0x3ffae6e0;
+    reserved[7].start = 0x3f800000;
+    reserved[7].end = 0x3fC00000;

    /* Sort by starting address */
    qsort(reserved, count, sizeof(soc_reserved_region_t), s_compare_reserved_regions);

    /* Validity checks */

Please reopen the issue.

Thomas

projectgus commented 5 years ago

Hi @neoniousTR ,

Thanks for letting us know that you're seeing this again. If you can reliably reproduce this, are you able to please provide the .elf, .map & .bin files for a bad build (and - if it's not too much trouble - a "good" build without the workaround - as well.)

You can email to me - angus at espressif.com - if that's convenient.

Does low.js project make any linker script changes, or is it all the default ESP-IDF linker setup?

ThomasRogg commented 5 years ago

Sorry, I cannot give more than hints, as we do not have the capacity to debug further.

What I can say:

The object files will be OK, because they do not have to be recompiled to get this working again. It is enough to just add additional string literals in other object files.

BTW: We are also using Mac OS. So it could be an issue which only happens on Macs.

MightyPork commented 5 years ago

If it's of any help, I just had a crash with the same error message:

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:2
load:0x3fff0018,len:4
load:0x3fff001c,len:6056
load:0x40078000,len:9712
ho 0 tail 12 room 4
load:0x40080400,len:6376
entry 0x40080728
I (30) boot: ESP-IDF v3.3-beta1-223-ga62cbfec9 2nd stage bootloader
I (30) boot: compile time 10:26:31
I (39) boot: Enabling RNG early entropy source...
I (40) boot: SPI Speed      : 40MHz
I (41) boot: SPI Mode       : DIO
I (45) boot: SPI Flash Size : 2MB
I (49) boot: Partition Table:
I (53) boot: ## Label            Usage          Type ST Offset   Length
I (60) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (68) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (75) boot:  2 factory          factory app      00 00 00010000 00100000
I (83) boot: End of partition table
I (87) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x1fffc (131068) map
I (141) esp_image: segment 1: paddr=0x00030024 vaddr=0x3ff80000 size=0x00000 (     0) load
I (141) esp_image: segment 2: paddr=0x0003002c vaddr=0x3ff80000 size=0x00000 (     0) load
I (148) esp_image: segment 3: paddr=0x00030034 vaddr=0x3ffb0000 size=0x02c5c ( 11356) load
I (161) esp_image: segment 4: paddr=0x00032c98 vaddr=0x3ffb2c5c size=0x00000 (     0) load
I (166) esp_image: segment 5: paddr=0x00032ca0 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _WindowOverflow4 at /home/ondra/esp/esp-idf/components/freertos/xtensa_vectors.S:1685

I (175) esp_image: segment 6: paddr=0x000330a8 vaddr=0x40080400 size=0x0cf68 ( 53096) load
I (204) esp_image: segment 7: paddr=0x00040018 vaddr=0x400d0018 size=0x8b454 (570452) map
0x400d0018: _stext at ??:?

I (402) esp_image: segment 8: paddr=0x000cb474 vaddr=0x4008d368 size=0x03f38 ( 16184) load
0x4008d368: vTaskSwitchContext at /home/ondra/esp/esp-idf/components/freertos/tasks.c:3537

I (409) esp_image: segment 9: paddr=0x000cf3b4 vaddr=0x400c0000 size=0x00000 (     0) load
I (409) esp_image: segment 10: paddr=0x000cf3bc vaddr=0x50000000 size=0x00000 (     0) load
I (418) esp_image: segment 11: paddr=0x000cf3c4 vaddr=0x50000000 size=0x00000 (     0) load
I (437) boot: Loaded app from partition at offset 0x10000
I (437) boot: Disabling RNG early entropy source...
I (439) cpu_start: Pro cpu up.
I (442) cpu_start: Application information:
I (447) cpu_start: Project name:     fbnode
I (452) cpu_start: App version:      1
I (457) cpu_start: Compile time:     10:26:09
I (462) cpu_start: Compile date:     Jan 24 2019
I (467) cpu_start: ESP-IDF:          v3.3-beta1-223-ga62cbfec9
I (473) cpu_start: Starting app cpu, entry point is 0x400810f4
0x400810f4: call_start_cpu1 at /home/ondra/esp/esp-idf/components/esp32/cpu_start.c:265

I (465) cpu_start: App cpu up.
E (484) memory_layout: SOC_RESERVE_MEMORY_REGION region range 0xfffffffc - 0x00000000 overlaps with 0xffffffff - 0xffffffff
abort() was called at PC 0x4011c57f on core 0
0x4011c57f: s_prepare_reserved_regions at /home/ondra/esp/esp-idf/components/soc/src/memory_layout_utils.c:97
 (inlined by) soc_get_available_memory_regions at /home/ondra/esp/esp-idf/components/soc/src/memory_layout_utils.c:114

Backtrace: 0x4009031b:0x3ffe3550 0x40090615:0x3ffe3570 0x4011c57f:0x3ffe3590 0x400d3b99:0x3ffe38e0 0x4008130e:0x3ffe3c60 0x40078e91:0x3ffe3c80 0x40079331:0x3ffe3cc0 0x40080776:0x3ffe3df0 0x40007c31:0x3ffe3eb0 0x4000073d:0x3ffe3f20
0x4009031b: invoke_abort at /home/ondra/esp/esp-idf/components/esp32/panic.c:707

0x40090615: abort at /home/ondra/esp/esp-idf/components/esp32/panic.c:707

0x4011c57f: s_prepare_reserved_regions at /home/ondra/esp/esp-idf/components/soc/src/memory_layout_utils.c:97
 (inlined by) soc_get_available_memory_regions at /home/ondra/esp/esp-idf/components/soc/src/memory_layout_utils.c:114

0x400d3b99: heap_caps_init at /home/ondra/esp/esp-idf/components/heap/heap_caps_init.c:65

0x4008130e: call_start_cpu0 at /home/ondra/esp/esp-idf/components/esp32/cpu_start.c:250

I'm using Arch Linux

idf clean nor idf fullclean helped, now trying the workarounds from here, reflashing bootloader etc..

it started after a small change in some embedded binary files


update - it seems fixed after I deleted esp-idf (with the bad un-cleaned files, presumably...) and made a fresh clone in the same location

igrr commented 5 years ago

@MightyPork

vaddr=0x3f400020 size=0x1fffc

This looks like the same issue as #2966, a fix for which has been just recently merged in https://github.com/espressif/esp-idf/commit/07645955a269a8db0504952d11f67d08f46af4cd

(Note that this doesn't explain the original report, where DROM size is not near 64kB boundary)

mpbejo commented 5 years ago

I think I have found the same problem using Arduino ESP32 1.0.1 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:1100 load:0x40078000,len:10088 load:0x40080400,len:6380 entry 0x400806a4 Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled. Core 0 register dump: PC : 0x401552f5 PS : 0x00060930 A0 : 0x801b30ee A1 : 0x3ffe3470
A2 : 0x3f41954c A3 : 0x00000059 A4 : 0x3f419680 A5 : 0x3f419528
A6 : 0x3ffe3530 A7 : 0x3ffe3520 A8 : 0x801552f5 A9 : 0x3ffe3450
A10 : 0x00000000 A11 : 0x3ffe3528 A12 : 0x00000000 A13 : 0x00000001
A14 : 0x3ffe34f0 A15 : 0x3ffe34f0 SAR : 0x00000010 EXCCAUSE: 0x0000001c
EXCVADDR: 0x0000000c LBEG : 0x4000c2e0 LEND : 0x4000c2f6 LCOUNT : 0x00000000

Backtrace: 0x401552f5:0x3ffe3470 0x401b30eb:0x3ffe34a0 0x401b31a5:0x3ffe34d0 0x40173ea5:0x3ffe3840 0x40083621:0x3ffe3c20 0x40078fb3:0x3ffe3c40 0x40079019:0x3ffe3c70 0x40079024:0x3ffe3ca0 0x400791c3:0x3ffe3cc0 0x400806d6:0x3ffe3df0 0x40007c31:0x3ffe3eb0 0x4000073d:0x3ffe3f20

Decoding stack results 0x401552f5: __assert_func at ../../../.././newlib/libc/stdlib/assert.c line 59 0x401b30eb: s_prepare_reserved_regions at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/soc/src/memory_layout_utils.c line 89 0x401b31a5: soc_get_available_memory_regions at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/soc/src/memory_layout_utils.c line 114 0x40173ea5: heap_caps_init at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/heap_caps_init.c line 65 0x40083621: call_start_cpu0 at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/cpu_start.c line 250

If I compile using Core Debug Level Info or Verbose the Sketch run, I also try to comment some Serial.print and the problem disappear. Which files I have to change to solve this problem on Arduino Thank You Best regards Marco

morganrallen commented 5 years ago

I'm seeing a very similar issue to this when bringing an application up to the current master (6fe853a2c). Main difference that I see is this ends up in Guru Mediation LoadProhibited.

Rebooting...
ets Jun  8 2016 00:22:57

rst:0xc (SW_CPU_RESET),boot:0x17 (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:0x3fff0018,len:4
load:0x3fff001c,len:8752
ho 0 tail 12 room 4
load:0x40078000,len:11904
load:0x40080400,len:7064
entry 0x400807a4
D (75) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
I (37) boot: ESP-IDF v4.0-dev-1381-g6fe853a2c 2nd stage bootloader
I (37) boot: compile time 20:14:21
D (37) boot: Enabling RTCWDT(9000 ms)
I (42) boot: Enabling RNG early entropy source...
D (48) boot: magic e9
D (50) boot: segments 04
D (52) boot: spi_mode 02
D (55) boot: spi_speed 00
D (58) boot: spi_size 02
I (60) boot: SPI Speed      : 40MHz
I (65) boot: SPI Mode       : DIO
I (69) boot: SPI Flash Size : 4MB
D (73) bootloader_flash: mmu set paddr=00000000 count=1 size=c00 src_addr=8000 src_addr_aligned=0
D (81) boot: mapped partition table 0x8000 at 0x3f408000
D (87) flash_parts: partition table verified, 3 entries
I (92) boot: Partition Table:
I (96) boot: ## Label            Usage          Type ST Offset   Length
D (103) boot: load partition table entry 0x3f408000
D (108) boot: type=1 subtype=2
I (111) boot:  0 nvs              WiFi data        01 02 00009000 00006000
D (119) boot: load partition table entry 0x3f408020
D (124) boot: type=1 subtype=1
I (127) boot:  1 phy_init         RF data          01 01 0000f000 00001000
D (134) boot: load partition table entry 0x3f408040
D (139) boot: type=0 subtype=0
I (142) boot:  2 factory          factory app      00 00 00010000 00100000
I (150) boot: End of partition table
D (154) boot: Trying partition index -1 offs 0x10000 size 0x100000
D (160) esp_image: reading image header @ 0x10000
D (165) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (172) esp_image: image header: 0xe9 0x06 0x02 0x02 40081048
I (178) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x09520 ( 38176) map
D (187) esp_image: free data page_count 0x00000032
D (192) bootloader_flash: mmu set paddr=00010000 count=1 size=9520 src_addr=10020 src_addr_aligned=10000
D (215) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
I (215) esp_image: segment 1: paddr=0x00019548 vaddr=0x3ffb0000 size=0x02208 (  8712) load
D (220) esp_image: free data page_count 0x00000032
D (224) bootloader_flash: mmu set paddr=00010000 count=1 size=2208 src_addr=19548 src_addr_aligned=10000
D (238) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
I (241) esp_image: segment 2: paddr=0x0001b758 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _WindowOverflow4 at /home/morgan/devel/esp-idf/components/freertos/xtensa_vectors.S:1778

D (250) esp_image: free data page_count 0x00000032
D (255) bootloader_flash: mmu set paddr=00010000 count=1 size=400 src_addr=1b758 src_addr_aligned=10000
D (265) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
I (271) esp_image: segment 3: paddr=0x0001bb60 vaddr=0x40080400 size=0x044b0 ( 17584) load
D (280) esp_image: free data page_count 0x00000032
D (285) bootloader_flash: mmu set paddr=00010000 count=2 size=44b0 src_addr=1bb60 src_addr_aligned=10000
D (302) bootloader_flash: mmu set block paddr=0x00020000 (was 0xffffffff)
I (302) esp_image: segment 4: paddr=0x00020018 vaddr=0x400d0018 size=0x15480 ( 87168) map
0x400d0018: _flash_cache_start at ??:?

D (310) esp_image: free data page_count 0x00000032
D (315) bootloader_flash: mmu set paddr=00020000 count=2 size=15480 src_addr=20018 src_addr_aligned=20000
D (356) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
I (356) esp_image: segment 5: paddr=0x000354a0 vaddr=0x400848b0 size=0x051f8 ( 20984) load
0x400848b0: multi_heap_free_impl at /home/morgan/devel/esp-idf/components/heap/multi_heap.c:501

D (360) esp_image: free data page_count 0x00000032
D (365) bootloader_flash: mmu set paddr=00030000 count=1 size=51f8 src_addr=354a0 src_addr_aligned=30000
D (384) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
D (384) esp_image: Calculated hash: f1b30a0d85240b22a6caa2088a0286c8e901b61a6d94fdbab4a6dc700d80558a
D (391) bootloader_flash: mmu set paddr=00030000 count=1 size=20 src_addr=3a6a0 src_addr_aligned=30000
D (400) bootloader_flash: mmu set paddr=00030000 count=1 size=20 src_addr=3a6a0 src_addr_aligned=30000
I (415) boot: Loaded app from partition at offset 0x10000
I (416) boot: Disabling RNG early entropy source...
D (421) boot: Mapping segment 0 as DROM
D (425) boot: Mapping segment 4 as IROM
D (429) boot: calling set_cache_and_start_app
D (433) boot: configure drom and irom and start
D (438) boot: start: 0x40081048
0x40081048: call_start_cpu0 at /home/morgan/devel/esp-idf/components/esp32/cpu_start.c:121

I (441) cpu_start: Pro cpu up.
I (445) cpu_start: Application information:
I (450) cpu_start: Project name:     cacoffiny
I (455) cpu_start: App version:      8a45a5f-dirty
I (460) cpu_start: Compile time:     Aug  4 2019 20:14:28
I (466) cpu_start: ELF file SHA256:  f29943c5cdf03d4e...
I (472) cpu_start: ESP-IDF:          v4.0-dev-1381-g6fe853a2c
I (479) cpu_start: Starting app cpu, entry point is 0x40080ffc
0x40080ffc: call_start_cpu1 at /home/morgan/devel/esp-idf/components/esp32/cpu_start.c:281

I (467) cpu_start: App cpu up.
V (489) memory_layout: reserved range is 0x3f4094f8 - 0x3f409540
D (495) memory_layout: Checking 11 reserved memory ranges:
D (501) memory_layout: Reserved memory range 0x3ffae000 - 0x3ffae6e0
D (507) memory_layout: Reserved memory range 0x3ffae6e0 - 0x3ffaff10
D (514) memory_layout: Reserved memory range 0x3ffb0000 - 0x3ffb3238
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.
Core 0 register dump:
PC      : 0x400d659a  PS      : 0x00060b30  A0      : 0x800d5ad4  A1      : 0x3ffe3440  
0x400d659a: __assert_func at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/stdlib/../../../.././newlib/libc/stdlib/assert.c:59

A2      : 0x3f4078dc  A3      : 0x0000005b  A4      : 0x3f407bd8  A5      : 0x3f407920  
A6      : 0x00000000  A7      : 0xffffffff  A8      : 0x800d659a  A9      : 0x3ffe3420  
A10     : 0x00000000  A11     : 0x3ffe33e8  A12     : 0x3ffe338f  A13     : 0x00000038  
A14     : 0x00000000  A15     : 0x3ffe3399  SAR     : 0x00000005  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x0000000c  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0x00000000  

ELF file SHA256: f29943c5cdf03d4eaf59b5726bf6ae1f837e345d82b419d8849d545505e007fc

Backtrace: 0x400d6597:0x3ffe3440 0x400d5ad1:0x3ffe3470 0x400d5b75:0x3ffe34a0 0x400d2356:0x3ffe3820 0x4008121e:0x3ffe3bf0 0x4007930e:0x3ffe3c30 |<-CORRUPTED
0x400d6597: __assert_func at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/stdlib/../../../.././newlib/libc/stdlib/assert.c:59

0x400d5ad1: s_prepare_reserved_regions at /home/morgan/devel/esp-idf/components/soc/src/memory_layout_utils.c:91 (discriminator 1)

0x400d5b75: soc_get_available_memory_regions at /home/morgan/devel/esp-idf/components/soc/src/memory_layout_utils.c:114

0x400d2356: heap_caps_init at /home/morgan/devel/esp-idf/components/heap/heap_caps_init.c:67

0x4008121e: call_start_cpu0 at /home/morgan/devel/esp-idf/components/esp32/cpu_start.c:266
rbruneau-altyor commented 1 year ago

Hi @igrr, it seems like the problem still exists on esp-idf v5.0.1. I just encountered it, with the following error message: memory_layout: SOC_RESERVE_MEMORY_REGION region range 0x14440014 - 0x1d040014 overlaps with 0x1c040054 - 0x5c040054

Changing log level or adding random extra log solved the issue, but it is very confusing to me. Where does this come from?

igrr commented 1 year ago

@rbruneau-altyor Could you please attach the .map and .elf file of the application build which exhibits this issue? Or, if you can't share it publicly, send it to me over email (ivan at espressif). We will try to figure out what might be the reason based on these files.

rbruneau-altyor commented 1 year ago

@igrr I unfortunately added logs everywhere in my project and can't remember the configuration that failed (yes, I should have saved somewhere but I was too happy to find that adding log made it worked again 😨 ) Though, I randomly get this issue with the project I am working on, so I soon as I get the error, I'll send you the the files

Note that I use ESP32-S3 with 8MB of PSRAM enabled

rbruneau-altyor commented 1 year ago

I actually managed to reproduce it: image @igrr I sent you the .elf and .bin file on your email

puyoulu commented 1 year ago

@igrr I think this issue is because the psram vaddr overlaps with instruction address:

V (176) mmu: found laddr is 0x70000
V (177) esp_psram: 8bit-aligned-range: 0x800000 B, starting from: 0x3c070000
V (203) memory_layout: reserved range is 0x3c078a30 - 0x3c078a50

This can be reproduced when size of .flash.text is exactly 1~31 bytes under MMU_PAGE_SIZE boudary:

.flash.text     0x0000000042000020    0x4fff7
                0x0000000042000020                _instruction_reserved_start = ABSOLUTE (.)
                0x0000000042050017                _instruction_reserved_end = ABSOLUTE (.)
                0x000000003c060020                _rodata_reserved_start = .
                0x000000003c078a30                soc_reserved_memory_region_start = ABSOLUTE (.)
                0x000000003c078a50                soc_reserved_memory_region_end = ABSOLUTE (.)
                0x000000003c078a60                _rodata_reserved_end = ABSOLUTE (.)

I solved this with below patch (and similar works for all chips):

--- a/components/esp_system/ld/esp32s3/sections.ld.in
+++ b/components/esp_system/ld/esp32s3/sections.ld.in
@@ -261,6 +261,7 @@ SECTIONS
       * dummy bytes to ensure this
       */
     . += _esp_flash_mmap_prefetch_pad_size;
+    . += 0x20;

     _text_end = ABSOLUTE(.);
     _instruction_reserved_end = ABSOLUTE(.);  /* This is a symbol marking the flash.text end, this can be used for mmu driver to maintain virtual address */
rbruneau-altyor commented 1 year ago

@puyoulu Thank you for your help. All you explained is a bit confusing to me, but a quick question : did I do something wrong in my configuration? I'd rather correct my code/project than modifying files I don't really understand...

puyoulu commented 1 year ago

@puyoulu Thank you for your help. All you explained is a bit confusing to me, but a quick question : did I do something wrong in my configuration? I'd rather correct my code/project than modifying files I don't really understand...

I don't think so. It is because the mmu management code does not calculate code size correctly.

rbruneau-altyor commented 1 year ago

Alright, then I will try your solution. Thank you!

puyoulu commented 1 year ago

I'm using idf v5.0.2, and I checked master branch, backporting commit 98892a3 should also fix this. But seems there are other codes rely _instruction_reserved_start/_instruction_reserved_end to calculate irom size (eg. components/esp_system/port/cpu_start.c), and maybe this commit need also be applied there?

Icarus113 commented 1 year ago

@puyoulu Thanks for helping pointing this out. The commit you mentioned does need to be backported to v5.0.x release. We will do this soon.

WRT this question:

But seems there are other codes rely _instruction_reserved_start/_instruction_reserved_end to calculate irom size (eg. components/esp_system/port/cpu_start.c), and maybe this commit need also be applied there?

May I know if you're referring to the calculations about this function?


Just attach more backgrounds / plans:

May I know if you're referring to the calculations about this function?

This calculation is a legacy Chip-ROM bug, which will influence the flash_mmap driver available mmap range. On v5.0.x we will fix this in another way.

Alvin1Zhang commented 1 year ago

Thanks for reporting, feel free to reopen.