esp_eth: Cache disabled but cached memory region accessed (IDFGH-2263)

[szmodz]

esp_eth is using plain calloc to allocate the driver structures. This causes problems when SPIRAM_MALLOC_ALWAYSINTERNAL is set to 0 (or some other small value).

This happens in the latest master (93a8603).

For example,

esp-idf/components/esp_eth/src/esp_eth_phy_lan8720.c

Line 381 in 93a8603

phy_lan8720_t *lan8720 = calloc(1, sizeof(phy_lan8720_t));

Perhaps there are more similar problems. I think the codebase should be tested with SPIRAM_MALLOC_ALWAYSINTERNAL set to 0.

[szmodz]

Problems like this are relevant not only in the SPIRAM_MALLOC_ALWAYSINTERNAL = 0 case. They can also occur under heavy load, when the memory is nearly exhausted.

[suda-morris]

Cool, nice found! Yes we should make sure Ethernet driver can run under cache disabled (OTA with Ethernet).

[szmodz]

With the current master it's much worse. Lots of InstrFetchProhibited, all seem to be ethernet/esp_netif/glue related. Wifi doesn't work either.

[suda-morris]

Thanks for your reporting! @szmodz

Could you post your backtrace, sdkconfig and test code here? Or could you tell us how to reproduce this issue based on any of the examples inside esp-idf?

[szmodz]

Ok, but this is going to take a while. It's not as simple as it seemed initially. But it's very reproducible.

The backtrace doesn't explain much, it's a double exception (yay).

[szmodz]

Guru Meditation Error: Core 0 panic'ed (Unhandled debug exception)
Debug exception reason: BREAK instr
Core 0 register dump:
PC : 0x400803c0 PS : 0x00060c36 A0 : 0x00000000 A1 : 0x3ffc58e0
0x400803c0: _DoubleExceptionVector at /Users/xxx/esp-idf/components/freertos/xtensa_vectors.S:542

The rest is nonsense. I'm not excluding an issue on my side, but the same code worked fine under heavy load for 3 days with the previous master.

[szmodz]

seems this is the cause:
#4541

[Alvin1Zhang]

@szmodz Thanks for reporting, feel free to reopen if the issue still happens. Thanks.

[szmodz]

@Alvin1Zhang The problem is not solved. My last comment was referring to this:
#4406 (comment)

Instead, that turned out to be caused by #4541. The original problem remains. Sorry for the confusion.

I can't reopen the issue myself.

[suda-morris]

I test the basic Ethernet example with SPIRAM_MALLOC_ALWAYSINTERNAL set to zero, everything is OK.
PSRAM will take GPIO16 and GPIO17, Please Make Sure your Ethernet board won't use these GPIOs for other purpose.

[szmodz]

@suda-morris did you try OTA?

Guru Meditation Error: Core  0 panic'ed (Cache disabled but cached memory region accessed)
Core 0 register dump:
PC      : 0x400853d8  PS      : 0x00060034  A0      : 0x80085328  A1      : 0x3ffb1380  
0x400853d8: emac_hal_isr at /Users/szmodz/xxx/esp-idf/components/soc/esp32/emac_hal.c:564

A2      : 0x3f80a634  A3      : 0xb0000000  A4      : 0x00000000  A5      : 0x00000000  
A6      : 0x3ff42000  A7      : 0x70000005  A8      : 0xbad00bad  A9      : 0x90000000  
A10     : 0x00002000  A11     : 0xb0000000  A12     : 0x3ffc0ff0  A13     : 0x3ffc0fd0  
A14     : 0x001a0f80  A15     : 0x3ffc100c  SAR     : 0x0000001f  EXCCAUSE: 0x00000007  
EXCVADDR: 0x00000000  LBEG    : 0x40087aac  LEND    : 0x40087ada  LCOUNT  : 0x00000000  
0x40087aac: memcpy at /builds/idf/crosstool-NG/.build/HOST-x86_64-apple-darwin12/xtensa-esp32-elf/src/newlib/newlib/libc/machine/xtensa/memcpy.S:168

0x40087ada: memcpy at /builds/idf/crosstool-NG/.build/HOST-x86_64-apple-darwin12/xtensa-esp32-elf/src/newlib/newlib/libc/machine/xtensa/memcpy.S:201

Core 0 was running in ISR context:
EPC1    : 0x4008a5eb  EPC2    : 0x00000000  EPC3    : 0x00000000  EPC4    : 0x400853d8
0x4008a5eb: esp_rom_spiflash_read_status at /Users/szmodz/xxx/esp-idf/components/spi_flash/esp32/spi_flash_rom_patch.c:221

0x400853d8: emac_hal_isr at /Users/szmodz/xxx/esp-idf/components/soc/esp32/emac_hal.c:564


ELF file SHA256: 0d0bd0baad0bd0baad0bd0baad0bd0baad0bd0baad0bd0baad0bd0baad0bd0ba

Backtrace: 0x400853d5:0x3ffb1380 0x40085325:0x3ffb13b0 0x40083326:0x3ffb13d0 0x4008a5e8:0x3ffc0ef0 0x4008a636:0x3ffc0f20 0x4008a66e:0x3ffc0f50 0x4008a6f0:0x3ffc0f80 0x4008a812:0x3ffc0fa0 0x4008a8ba:0x3ffc0fd0 0x400843e7:0x3ffc0ff0 0x40131c4d:0x3ffc1050 0x40115bc6:0x3ffc1070 0x400df088:0x3ffc10c0 0x400db669:0x3ffc10e0 0x401118b9:0x3ffc1100 0x40111bf6:0x3ffc1130 0x40111d4f:0x3ffc1150 0x401120c6:0x3ffc1190 0x400df35a:0x3ffc11b0 0x4008eced:0x3ffc11e0
0x400853d5: emac_hal_isr at /Users/szmodz/xxx/esp-idf/components/soc/esp32/emac_hal.c:564

0x40085325: emac_esp32_isr_handler at /Users/szmodz/xxx/esp-idf/components/esp_eth/src/esp_eth_mac_esp32.c:365

0x40083326: _xt_lowint1 at /Users/szmodz/xxx/esp-idf/components/freertos/xtensa_vectors.S:1153

0x4008a5e8: esp_rom_spiflash_read_status at /Users/szmodz/xxx/esp-idf/components/spi_flash/esp32/spi_flash_rom_patch.c:221

0x4008a636: esp_rom_spiflash_wait_idle at /Users/szmodz/xxx/esp-idf/components/spi_flash/esp32/spi_flash_rom_patch.c:42

0x4008a66e: esp_rom_spiflash_enable_write at /Users/szmodz/xxx/esp-idf/components/spi_flash/esp32/spi_flash_rom_patch.c:299

0x4008a6f0: esp_rom_spiflash_program_page_internal at /Users/szmodz/xxx/esp-idf/components/spi_flash/esp32/spi_flash_rom_patch.c:171

0x4008a812: esp_rom_spiflash_write at /Users/szmodz/xxx/esp-idf/components/spi_flash/esp32/spi_flash_rom_patch.c:475

0x4008a8ba: esp_rom_spiflash_write_encrypted at /Users/szmodz/xxx/esp-idf/components/spi_flash/esp32/spi_flash_rom_patch.c:520

0x400843e7: spi_flash_write_encrypted_in_rows at /Users/szmodz/xxx/esp-idf/components/spi_flash/flash_ops.c:476
 (inlined by) spi_flash_write_encrypted at /Users/szmodz/xxx/esp-idf/components/spi_flash/flash_ops.c:506

0x40131c4d: esp_partition_write at /Users/szmodz/xxx/esp-idf/components/spi_flash/partition.c:398

[szmodz]

@suda-morris you don't need a test case for this. Visual inspection shows what the problem is.

esp-idf/components/esp_eth/src/esp_eth_mac_esp32.c

Line 378 in 7a7c4a5

emac = calloc(1, sizeof(emac_esp32_t));

emac_esp32_t (which contains emac_hal_context_t) is allocated using calloc, which returns a PSRAM pointer.

Later, there's

esp-idf/components/esp_eth/src/esp_eth_mac_esp32.c

Line 419 in 7a7c4a5

MAC_CHECK(esp_intr_alloc(ETS_ETH_MAC_INTR_SOURCE, ESP_INTR_FLAG_IRAM, emac_esp32_isr_handler,

(ESP_INTR_FLAG_IRAM)

[szmodz]

@suda-morris The driver works fine after fixing the PSRAM usage bugs. GPIO setup is ok.

[suda-morris]

@szmodz Ah yes, thanks for your detailed reporting, now we can reproduce it.

[szmodz]

There is another issue here:

esp-idf/components/esp_eth/src/esp_eth.c

Line 174 in 647cb62

esp_eth_driver_t *eth_driver = calloc(1, sizeof(esp_eth_driver_t));

esp-idf/components/esp_eth/src/esp_eth.c

Line 364 in 647cb62

esp_err_t esp_eth_increase_reference(esp_eth_handle_t hdl)

atomic_fetch_add / atomic_fetch_sub can't be used with PSRAM addresses as they rely on s32c1i.

Using stdatomic.h with PSRAM can cause some VERY hard to find problems. Probably should report a separate bug.

#include <stdatomic.h>

void xfaa(volatile int *x) {
    atomic_fetch_add(x, 1);
}

xtensa-esp32-elf-gcc -O2 -std=gnu11 -S test.c

	.file	"test.c"
	.text
	.align	4
	.global	xfaa
	.type	xfaa, @function
xfaa:
	entry	sp, 32
	memw
	l32i.n	a8, a2, 0
.L2:
	mov.n	a9, a8
	addi.n	a10, a8, 1
	wsr	a8, SCOMPARE1
	**s32c1i	a10, a2, 0**
	mov.n	a8, a10
	bne	a10, a9, .L2
	retw.n
	.size	xfaa, .-xfaa
	.ident	"GCC: (crosstool-NG esp-2019r2) 8.2.0"

[szmodz]

#4635