Page 1 of 1

spi write causes a crash with nested call

Posted: Tue Oct 22, 2019 3:45 pm
by julienD
Hello,

I'm running into a curious behaviour. I implemented a generic function to read a register from a external device through a spi communication:

Code: Select all

uint8_t spi_read_reg(uint8_t addr) {

    ESP_LOGI(TAG, "----------------read_reg at address %d -------------------------", addr);
    uint32_t toSend = addr & 0x7F;

    spi_transaction_t trans_desc;
    trans_desc.addr = toSend;
    trans_desc.cmd = 0;
    trans_desc.flags = SPI_TRANS_USE_RXDATA;
    trans_desc.length = 8 * 1;
    trans_desc.rxlength = 0;
    trans_desc.tx_buffer = &toSend;

    ESP_ERROR_CHECK(spi_device_transmit(device, &trans_desc));
    ESP_LOGI(TAG, "read addr %d : %d", addr, *((uint32_t* )trans_desc.rx_data));

    return *((uint32_t*) trans_desc.rx_data);
}
I did the same for a write operation:

Code: Select all

void spi_write_reg(uint8_t addr, uint8_t data) {
    ESP_LOGI(TAG, "-----------------write reg at address : %d, value : %d", addr, data);

    spi_transaction_t trans_desc;
    trans_desc.addr = addr;
    trans_desc.cmd = 1;
    trans_desc.flags = 0;
    trans_desc.length = 8 * 2;
    trans_desc.rxlength = 0;
    trans_desc.tx_buffer = &data;

    ESP_LOGI(TAG, "spi_device_transmit started");
    ESP_ERROR_CHECK(spi_device_transmit(device, &trans_desc));
    ESP_LOGI(TAG, "spi_device_transmit over");
}
Now, if I call this:

Code: Select all

   
    #define ADDRESS          0x01

    uint8_t x = spi_read_reg(ADDRESS) + 1;
    spi_write_reg(ADDRESS, x);
It works. But if I call this:

Code: Select all

   #define ADDRESS          0x01
   spi_write_reg(ADDRESS, spi_read_reg(ADDRESS) + 1);
The app crashes during the call to spi_device_transmit() and I don't really understand why...
I did try to increase main task stack size and other stack sizes unsucessfully.
Does anyone has a clue?
esp-idf version 4.0 commit a21eb04cc6b

Thanks
Julien

Here's the full log:

Code: Select all

rst:0x1 (POWERON_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:7696
ho 0 tail 12 room 4
load:0x40078000,len:19296
load:0x40080400,len:4368
entry 0x40080750
I (30) boot: ESP-IDF v4.0-beta1-180-ga21eb04cc-dirty 2nd stage bootloader
I (31) boot: compile time 17:37:17
I (32) boot: Enabling RNG early entropy source...
I (37) boot: SPI Speed      : 40MHz
I (41) boot: SPI Mode       : DIO
I (45) boot: SPI Flash Size : 4MB
I (49) boot: Partition Table:
I (53) boot: ## Label            Usage          Type ST Offset   Length
I (60) boot:  0 nvs              WiFi data        01 02 00011000 00004000
I (68) boot:  1 otadata          OTA data         01 00 00015000 00002000
I (75) boot:  2 factory          factory app      00 00 00020000 00100000
I (83) boot:  3 ota_0            OTA app          00 10 00120000 00100000
I (90) boot:  4 ota_1            OTA app          00 11 00220000 00100000
I (98) boot: End of partition table
I (102) boot: Defaulting to factory image
I (107) esp_image: segment 0: paddr=0x00020020 vaddr=0x3f400020 size=0x08990 ( 35216) map
I (128) esp_image: segment 1: paddr=0x000289b8 vaddr=0x3ffb0000 size=0x020a8 (  8360) load
I (132) esp_image: segment 2: paddr=0x0002aa68 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _WindowOverflow4 at /home/ju/tools/esp/esp-idf/components/freertos/xtensa_vectors.S:1778

I (136) esp_image: segment 3: paddr=0x0002ae70 vaddr=0x40080400 size=0x051a0 ( 20896) load
I (153) esp_image: segment 4: paddr=0x00030018 vaddr=0x400d0018 size=0x189cc (100812) map
0x400d0018: _stext at ??:?

I (190) esp_image: segment 5: paddr=0x000489ec vaddr=0x400855a0 size=0x05f04 ( 24324) load
0x400855a0: multi_heap_realloc_impl at /home/ju/tools/esp/esp-idf/components/heap/multi_heap.c:593

I (200) esp_image: Verifying image signature...
I (614) boot: Loaded app from partition at offset 0x20000
I (615) boot: Disabling RNG early entropy source...
I (615) cpu_start: Pro cpu up.
I (619) cpu_start: Application information:
I (623) cpu_start: Project name:     afficheur
I (629) cpu_start: App version:      1
I (633) cpu_start: Compile time:     Oct 22 2019 17:37:13
I (639) cpu_start: ELF file SHA256:  05ad51d2e07769ff...
I (645) cpu_start: ESP-IDF:          v4.0-beta1-180-ga21eb04cc-dirty
I (652) cpu_start: Starting app cpu, entry point is 0x400811b8
0x400811b8: call_start_cpu1 at /home/ju/tools/esp/esp-idf/components/esp32/cpu_start.c:272

I (0) cpu_start: App cpu up.
D (662) memory_layout: Checking 7 reserved memory ranges:
D (668) memory_layout: Reserved memory range 0x3ffae000 - 0x3ffae6e0
D (674) memory_layout: Reserved memory range 0x3ffb0000 - 0x3ffb3128
D (680) memory_layout: Reserved memory range 0x3ffe0000 - 0x3ffe0440
D (687) memory_layout: Reserved memory range 0x3ffe3f20 - 0x3ffe4350
D (693) memory_layout: Reserved memory range 0x40070000 - 0x40078000
D (700) memory_layout: Reserved memory range 0x40078000 - 0x40080000
0x40080000: _WindowOverflow4 at /home/ju/tools/esp/esp-idf/components/freertos/xtensa_vectors.S:1778

D (706) memory_layout: Reserved memory range 0x40080000 - 0x4008b4a4
0x40080000: _WindowOverflow4 at /home/ju/tools/esp/esp-idf/components/freertos/xtensa_vectors.S:1778

D (713) memory_layout: Building list of available memory regions:
D (719) memory_layout: Available memory region 0x3ffae6e0 - 0x3ffb0000
D (725) memory_layout: Available memory region 0x3ffb3128 - 0x3ffb8000
D (732) memory_layout: Available memory region 0x3ffb8000 - 0x3ffc0000
D (739) memory_layout: Available memory region 0x3ffc0000 - 0x3ffc2000
D (745) memory_layout: Available memory region 0x3ffc2000 - 0x3ffc4000
D (752) memory_layout: Available memory region 0x3ffc4000 - 0x3ffc6000
D (758) memory_layout: Available memory region 0x3ffc6000 - 0x3ffc8000
D (765) memory_layout: Available memory region 0x3ffc8000 - 0x3ffca000
D (772) memory_layout: Available memory region 0x3ffca000 - 0x3ffcc000
D (778) memory_layout: Available memory region 0x3ffcc000 - 0x3ffce000
D (785) memory_layout: Available memory region 0x3ffce000 - 0x3ffd0000
D (791) memory_layout: Available memory region 0x3ffd0000 - 0x3ffd2000
D (798) memory_layout: Available memory region 0x3ffd2000 - 0x3ffd4000
D (805) memory_layout: Available memory region 0x3ffd4000 - 0x3ffd6000
D (811) memory_layout: Available memory region 0x3ffd6000 - 0x3ffd8000
D (818) memory_layout: Available memory region 0x3ffd8000 - 0x3ffda000
D (824) memory_layout: Available memory region 0x3ffda000 - 0x3ffdc000
D (831) memory_layout: Available memory region 0x3ffdc000 - 0x3ffde000
D (837) memory_layout: Available memory region 0x3ffde000 - 0x3ffe0000
D (844) memory_layout: Available memory region 0x3ffe0440 - 0x3ffe3f20
D (851) memory_layout: Available memory region 0x3ffe4350 - 0x3ffe8000
D (857) memory_layout: Available memory region 0x3ffe8000 - 0x3fff0000
D (864) memory_layout: Available memory region 0x3fff0000 - 0x3fff8000
D (870) memory_layout: Available memory region 0x3fff8000 - 0x3fffc000
D (877) memory_layout: Available memory region 0x3fffc000 - 0x40000000
D (884) memory_layout: Available memory region 0x4008b4a4 - 0x4008c000
D (890) memory_layout: Available memory region 0x4008c000 - 0x4008e000
D (897) memory_layout: Available memory region 0x4008e000 - 0x40090000
D (903) memory_layout: Available memory region 0x40090000 - 0x40092000
D (910) memory_layout: Available memory region 0x40092000 - 0x40094000
D (917) memory_layout: Available memory region 0x40094000 - 0x40096000
D (923) memory_layout: Available memory region 0x40096000 - 0x40098000
D (930) memory_layout: Available memory region 0x40098000 - 0x4009a000
D (936) memory_layout: Available memory region 0x4009a000 - 0x4009c000
D (943) memory_layout: Available memory region 0x4009c000 - 0x4009e000
D (950) memory_layout: Available memory region 0x4009e000 - 0x400a0000
I (956) heap_init: Initializing. RAM available for dynamic allocation:
D (963) heap_init: New heap initialised at 0x3ffae6e0
I (969) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
D (975) heap_init: New heap initialised at 0x3ffb3128
I (980) heap_init: At 3FFB3128 len 0002CED8 (179 KiB): DRAM
I (986) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (992) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
D (999) heap_init: New heap initialised at 0x4008b4a4
I (1004) heap_init: At 4008B4A4 len 00014B5C (82 KiB): IRAM
I (1010) cpu_start: Pro cpu start user code
D (1022) clk: RTC_SLOW_CLK calibration value: 3249574
D (1032) intr_alloc: Connected src 46 to int 2 (cpu 0)
D (1033) intr_alloc: Connected src 57 to int 3 (cpu 0)
D (1033) stack_chk: Intialize random stack guard
D (1038) intr_alloc: Connected src 24 to int 9 (cpu 0)
D (1043) FLASH_HAL: extra_dummy: 1
D (1046) spi_flash: trying chip: issi
D (1050) spi_flash: trying chip: generic
I (1054) spi_flash: detected chip: generic
I (1059) spi_flash: flash io: dio
D (1063) efuse: coding scheme 0
D (1066) efuse: In EFUSE_BLK0__DATA3_REG is used 1 bits starting with 15 bit
D (1073) efuse: coding scheme 0
D (1076) efuse: In EFUSE_BLK0__DATA5_REG is used 1 bits starting with 20 bit
I (1083) cpu_start: Chip Revision: 1
W (1088) cpu_start: Chip revision is higher than the one configured in menuconfig. Suggest to upgrade it.
I (1098) cpu_start: Starting scheduler on PRO CPU.
D (0) intr_alloc: Connected src 25 to int 2 (cpu 1)
I (0) cpu_start: Starting scheduler on APP CPU.
D (1113) heap_init: New heap initialised at 0x3ffe0440
D (1123) heap_init: New heap initialised at 0x3ffe4350
D (1133) intr_alloc: Connected src 16 to int 12 (cpu 0)
D (1133) nvs: nvs_flash_init_custom partition=nvs start=17 count=4
D (1173) spi: SPI2 use gpio matrix.
D (1173) intr_alloc: Connected src 30 to int 13 (cpu 0)
D (1173) spi_hal: eff: 10, limit: 20000k(/3), 0 dummy, -1 delay
D (1173) spi_master: SPI2: New device added to CS0, effective clock: 10kHz
I (1183) main: ----------------read_reg at address 1 -------------------------
D (1193) spi_master: SPI device changed from 3 to 0
I (1203) main: read addr 1 : 8
I (1203) main: -----------------write reg at address : 1, value : 9
I (1213) main: spi_device_transmit started
I (1213) spi_master: Allocate RX buffer for DMA
Guru Meditation Error: Core  0 panic'ed (StoreProhibited). Exception was unhandled.
Core 0 register dump:
PC      : 0x4000c325  PS      : 0x00060530  A0      : 0x80082dff  A1      : 0x3ffb4eb0  
A2      : 0x00000008  A3      : 0x3ffb6c6a  A4      : 0x00000002  A5      : 0x00000008  
A6      : 0x00001a08  A7      : 0x00000000  A8      : 0x00000000  A9      : 0x3ffb4e70  
A10     : 0x00000003  A11     : 0x00060723  A12     : 0x00060720  A13     : 0x3ffb4efc  
A14     : 0x3ffb6c68  A15     : 0x3ffb4f6c  SAR     : 0x00000004  EXCCAUSE: 0x0000001d  
EXCVADDR: 0x00000008  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0xffffffff  

ELF file SHA256: 05ad51d2e07769ff5a313c96da7e940b32098e6aafc727b5a0966972b5c28ad2

Backtrace: 0x4000c322:0x3ffb4eb0 |<-CORRUPTED

CPU halted.


Re: spi write causes a crash with nested call

Posted: Wed Oct 23, 2019 7:44 am
by julienD
Some more information:

This morning, I went back to 3.3 with the same behaviour but, it allows me to get a stack trace:

Code: Select all

Guru Meditation Error: Core  0 panic'ed (StoreProhibited). Exception was unhandled.
Core 0 register dump:
PC      : 0x4000c325  PS      : 0x00060d30  A0      : 0x8008307d  A1      : 0x3ffb4d80  
A2      : 0x00000008  A3      : 0x3ffb3aa6  A4      : 0x00000002  A5      : 0x00000008  
A6      : 0x00001a08  A7      : 0x00000000  A8      : 0x00000000  A9      : 0x3ffb4d40  
A10     : 0x00000003  A11     : 0x00060b23  A12     : 0x00060b20  A13     : 0x3ffb4dcc  
A14     : 0x3ffb3aa4  A15     : 0x3ffb4e3c  SAR     : 0x00000004  EXCCAUSE: 0x0000001d  
EXCVADDR: 0x00000008  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0xffffffff  

ELF file SHA256: 481ea57d050b90ecca376930d76273695b3d986879af943aa72e0970ee782234

Backtrace: 0x4000c325:0x3ffb4d80 0x4008307a:0x3ffb4d90 0x400e2ca9:0x3ffb4db0 0x400e2cf2:0x3ffb4df0 0x400d23b9:0x3ffb4e20 0x400d24de:0x3ffb4e90 0x400d2532:0x3ffb4eb0 0x400d0d7e:0x3ffb4ed0 0x40086691:0x3ffb4ef0
0x4008307a: uninstall_priv_desc at /home/ju/tools/esp/esp-idf/components/driver/spi_master.c:547

0x400e2ca9: spi_device_get_trans_result at /home/ju/tools/esp/esp-idf/components/driver/spi_master.c:1243

0x400e2cf2: spi_device_transmit at /home/ju/tools/esp/esp-idf/components/driver/spi_master.c:1258

0x400d23b9: spi_write_reg at /home/ju/dev/embedded/build/../main/main.c:56

0x400d24de: test at /home/ju/dev/embedded/uild/../main/main.c:103

0x400d2532: app_main at /home/ju/dev/embedded/build/../main/main.c:115

0x400d0d7e: main_task at /home/ju/tools/esp/esp-idf/components/esp32/cpu_start.c:551

0x40086691: vPortTaskWrapper at /home/ju/tools/esp/esp-idf/components/freertos/port.c:403



Re: spi write causes a crash with nested call

Posted: Wed Oct 23, 2019 12:40 pm
by julienD
Looks like spi_device_transmit() should specify SPI_TRANS_USE_RXDATA even if rxlength is 0.