STM32CubeF7 icon indicating copy to clipboard operation
STM32CubeF7 copied to clipboard

QSPI still times out on 32F769IDISCOVERY

Open Jookia opened this issue 1 year ago • 14 comments

Describe the set-up

I'm using the 32F769IDISCOVERY board and Mbed OS 6.17.

Describe the bug

The HAL_QSPI_Transmit sometimes times out instead of returning data.

How To Reproduce

Run this using Mbed CLI1:

mkdir project1
cd project1
mbed new .
wget https://github.com/ARMmbed/mbed-os/files/7233465/main.cpp.txt
wget https://github.com/ARMmbed/mbed-os/files/7233470/target.json.txt
mv main.cpp.txt main.cpp
mv target.json.txt mbed_app.json
mbed compile -t GCC_ARM -m DISCO_F769NI -f

Watch on serial (115200 baud) for an error. This took half an hour for me, and an hour for a friend.

Additional context

I've reported this bug before as #52 . There was a release afterwards but this didn't fix it. I decided to give it some time and try again to see if the issue still happens.

I'm confident the fix is still the same: Clear the busy bit like some other chip variants do.

Edit: I have backported the v1.17 QSPI driver to Mbed and have the same results.

Jookia avatar Mar 09 '23 17:03 Jookia

I observed similar effect with -O3 gcc flag. First operation sometimes fails with timeout, but second is successful. Set optimisation for size -Os fixes the problem. STM32F777, QSPI Nor Flash MX25L12833F at 108MHz/54MHz clock. arm-none-eabi toolchain version 7q2 works fine even with -O3, but others fails with -O3 and -O2

icis4 avatar May 07 '23 08:05 icis4

Are you sure it fixes it, or it just doesn't reproduce the issue?

On Sun, May 07, 2023 at 01:23:28AM -0700, Ivaylo Iltchev wrote:

I observed similar effect with -O3 gcc flag. First operation sometimes fails with timeout, but second is successful. Set optimisation for size -Os fixes the problem.

-- Reply to this email directly or view it on GitHub: https://github.com/STMicroelectronics/STM32CubeF7/issues/82#issuecomment-1537356590 You are receiving this because you authored the thread.

Message ID: @.***>

Jookia avatar May 08 '23 05:05 Jookia

Jookia, everything works just fine. I have a lot Robot Framework tests about this, customers stop complain and finally I removed workaround code about this. This code is used by the bootloader, external flash loader for Stm32CubeProgrammer and 4 application firmwares.

icis4 avatar May 08 '23 09:05 icis4

Could you show me how to reproduce this? I would like to compare assembly output.

On Mon, May 08, 2023 at 02:03:48AM -0700, Ivaylo Iltchev wrote:

Jookia, everything works just fine. I have a lot Robot Framework tests about this, customers stop complain and finally I removed workaround code about this.

-- Reply to this email directly or view it on GitHub: https://github.com/STMicroelectronics/STM32CubeF7/issues/82#issuecomment-1538017706 You are receiving this because you authored the thread.

Message ID: @.***>

Jookia avatar May 08 '23 09:05 Jookia

This is a pretty big project > .5 mil of lines, FreeRTOS, RNDIS, LwIP, Ethernet. I have FatFs on the half of this QSPI NOR Flash memory, another half is used for recovery application, FPGA image etc. First I hit this problem when checking crc32 of the file. Normally this takes around a second, but when read fails (not all, but up to 5 from 2000 blocks) it is takes more than 5 sec (5 sec for every timeout). If block fails, I had a workaround to read again - only one repeat was enough.

icis4 avatar May 08 '23 10:05 icis4

  * @brief  Reads Sector(s)
  * @param  pdrv: Physical drive number (0..)
  * @param  *buff: Data buffer to store read data
  * @param  sector: Sector address (LBA)
  * @param  count: Number of sectors to read (1..128)
  * @retval DRESULT: Operation result
  */
static DRESULT qspiflash_read (
	BYTE pdrv,      /* Physical drive nmuber to identify the drive */
	BYTE *buff,     /* Data buffer to store read data */
	DWORD sector,   /* Sector address in LBA */
	UINT count      /* Number of sectors to read */
)
{
	  if(BSP_QSPI_Read(buff,  FLASH_DEVICE_OFFSET + sector * BLOCK_SIZE, BLOCK_SIZE * count) != HAL_OK)
	  {
		  /* Error, try to reset QSPI and read one more time */
		  BSP_QSPI_Init();
		  if(BSP_QSPI_Read(buff,  FLASH_DEVICE_OFFSET + sector * BLOCK_SIZE, BLOCK_SIZE * count) != HAL_OK)
		  {
			  return RES_ERROR;
		  }
	  }

	  return RES_OK;
}

icis4 avatar May 08 '23 10:05 icis4

/**
 * @brief  Reads an amount of data from the QSPI memory.
 * @param  pData: Pointer to data to be read
 * @param  ReadAddr: Read start address
 * @param  Size: Size of data to read
 * @retval QSPI memory status
 */
uint8_t BSP_QSPI_Read(uint8_t* pData, uint32_t ReadAddr, uint32_t Size)
{
    QSPI_CommandTypeDef s_command;

    /* Initialize the read command */
    s_command.InstructionMode = QSPI_INSTRUCTION_4_LINES;
    s_command.Instruction = 0xEB;     //QPI_READ_4_BYTE_ADDR_CMD;
    s_command.AddressMode = QSPI_ADDRESS_4_LINES;
    s_command.AddressSize = QSPI_ADDRESS_24_BITS;
    s_command.Address = ReadAddr;
    s_command.AlternateByteMode = QSPI_ALTERNATE_BYTES_NONE;
    s_command.DataMode = QSPI_DATA_4_LINES;
    s_command.DummyCycles = MX25L128_DUMMY_CYCLES_READ_QUAD_IO;
    s_command.NbData = Size;
    s_command.DdrMode = QSPI_DDR_MODE_DISABLE;
    s_command.DdrHoldHalfCycle = QSPI_DDR_HHC_ANALOG_DELAY;
    s_command.SIOOMode = QSPI_SIOO_INST_EVERY_CMD;

    /* Configure the command */
    if (HAL_QSPI_Command(&QSPIHandle, &s_command, HAL_QPSI_TIMEOUT_DEFAULT_VALUE) != HAL_OK) {
        return QSPI_ERROR;
    }

    /* Set S# timing for Read command */
    MODIFY_REG(QSPIHandle.Instance->DCR, QUADSPI_DCR_CSHT, QSPI_CS_HIGH_TIME_1_CYCLE);

    /* Reception of the data */
    if (HAL_QSPI_Receive(&QSPIHandle, pData, HAL_QPSI_TIMEOUT_DEFAULT_VALUE) != HAL_OK) {
        return QSPI_ERROR;
    }

    /* Restore S# timing for nonRead commands */
    MODIFY_REG(QSPIHandle.Instance->DCR, QUADSPI_DCR_CSHT, QSPI_CS_HIGH_TIME_4_CYCLE);

    return QSPI_OK;
}

icis4 avatar May 08 '23 10:05 icis4

D-CACHE + C-CACHE are enabled.

icis4 avatar May 08 '23 11:05 icis4

Stm32CubeIDE 1.12.1, gnu arm-none-eabi 12rel1 -O3

08049e08 <BSP_QSPI_Read>:
* @param  ReadAddr: Read start address
* @param  Size: Size of data to read
* @retval QSPI memory status
*/
uint8_t BSP_QSPI_Read(uint8_t* pData, uint32_t ReadAddr, uint32_t Size)
{
8049e08:	b570      	push	{r4, r5, r6, lr}
   QSPI_CommandTypeDef s_command;

   /* Initialize the read command */
   s_command.InstructionMode = QSPI_INSTRUCTION_4_LINES;
   s_command.Instruction = 0xEB;     //QPI_READ_4_BYTE_ADDR_CMD;
8049e0a:	24eb      	movs	r4, #235	; 0xeb
{
8049e0c:	b08e      	sub	sp, #56	; 0x38
   s_command.DdrMode = QSPI_DDR_MODE_DISABLE;
   s_command.DdrHoldHalfCycle = QSPI_DDR_HHC_ANALOG_DELAY;
   s_command.SIOOMode = QSPI_SIOO_INST_EVERY_CMD;

   /* Configure the command */
   if (HAL_QSPI_Command(&QSPIHandle, &s_command, HAL_QPSI_TIMEOUT_DEFAULT_VALUE) != HAL_OK) {
8049e0e:	4d1c      	ldr	r5, [pc, #112]	; (8049e80 <BSP_QSPI_Read+0x78>)
   s_command.DummyCycles = MX25L128_DUMMY_CYCLES_READ_QUAD_IO;
8049e10:	2300      	movs	r3, #0
   s_command.NbData = Size;
8049e12:	920a      	str	r2, [sp, #40]	; 0x28
   s_command.DataMode = QSPI_DATA_4_LINES;
8049e14:	f04f 7240 	mov.w	r2, #50331648	; 0x3000000
   s_command.DummyCycles = MX25L128_DUMMY_CYCLES_READ_QUAD_IO;
8049e18:	9308      	str	r3, [sp, #32]
   s_command.DataMode = QSPI_DATA_4_LINES;
8049e1a:	9209      	str	r2, [sp, #36]	; 0x24
   s_command.DummyCycles = MX25L128_DUMMY_CYCLES_READ_QUAD_IO;
8049e1c:	f44f 7240 	mov.w	r2, #768	; 0x300
   s_command.SIOOMode = QSPI_SIOO_INST_EVERY_CMD;
8049e20:	930d      	str	r3, [sp, #52]	; 0x34
   s_command.DummyCycles = MX25L128_DUMMY_CYCLES_READ_QUAD_IO;
8049e22:	9206      	str	r2, [sp, #24]
   if (HAL_QSPI_Command(&QSPIHandle, &s_command, HAL_QPSI_TIMEOUT_DEFAULT_VALUE) != HAL_OK) {
8049e24:	f241 3288 	movw	r2, #5000	; 0x1388
   s_command.Instruction = 0xEB;     //QPI_READ_4_BYTE_ADDR_CMD;
8049e28:	e9cd 4100 	strd	r4, r1, [sp]
   s_command.AddressSize = QSPI_ADDRESS_24_BITS;
8049e2c:	f44f 5100 	mov.w	r1, #8192	; 0x2000
{
8049e30:	4604      	mov	r4, r0
   if (HAL_QSPI_Command(&QSPIHandle, &s_command, HAL_QPSI_TIMEOUT_DEFAULT_VALUE) != HAL_OK) {
8049e32:	4628      	mov	r0, r5
   s_command.AddressSize = QSPI_ADDRESS_24_BITS;
8049e34:	9103      	str	r1, [sp, #12]
   s_command.DummyCycles = MX25L128_DUMMY_CYCLES_READ_QUAD_IO;
8049e36:	2108      	movs	r1, #8
8049e38:	9105      	str	r1, [sp, #20]
8049e3a:	f44f 6140 	mov.w	r1, #3072	; 0xc00
8049e3e:	9107      	str	r1, [sp, #28]
   if (HAL_QSPI_Command(&QSPIHandle, &s_command, HAL_QPSI_TIMEOUT_DEFAULT_VALUE) != HAL_OK) {
8049e40:	4669      	mov	r1, sp
   s_command.DdrHoldHalfCycle = QSPI_DDR_HHC_ANALOG_DELAY;
8049e42:	e9cd 330b 	strd	r3, r3, [sp, #44]	; 0x2c
   if (HAL_QSPI_Command(&QSPIHandle, &s_command, HAL_QPSI_TIMEOUT_DEFAULT_VALUE) != HAL_OK) {
8049e46:	f7b9 fec5 	bl	8003bd4 <HAL_QSPI_Command>
8049e4a:	b110      	cbz	r0, 8049e52 <BSP_QSPI_Read+0x4a>
       return QSPI_ERROR;
8049e4c:	2001      	movs	r0, #1

   /* Restore S# timing for nonRead commands */
   MODIFY_REG(QSPIHandle.Instance->DCR, QUADSPI_DCR_CSHT, QSPI_CS_HIGH_TIME_4_CYCLE);

   return QSPI_OK;
}
8049e4e:	b00e      	add	sp, #56	; 0x38
8049e50:	bd70      	pop	{r4, r5, r6, pc}
   MODIFY_REG(QSPIHandle.Instance->DCR, QUADSPI_DCR_CSHT, QSPI_CS_HIGH_TIME_1_CYCLE);
8049e52:	682e      	ldr	r6, [r5, #0]
   if (HAL_QSPI_Receive(&QSPIHandle, pData, HAL_QPSI_TIMEOUT_DEFAULT_VALUE) != HAL_OK) {
8049e54:	f241 3288 	movw	r2, #5000	; 0x1388
8049e58:	4621      	mov	r1, r4
8049e5a:	4628      	mov	r0, r5
   MODIFY_REG(QSPIHandle.Instance->DCR, QUADSPI_DCR_CSHT, QSPI_CS_HIGH_TIME_1_CYCLE);
8049e5c:	6873      	ldr	r3, [r6, #4]
8049e5e:	f423 63e0 	bic.w	r3, r3, #1792	; 0x700
8049e62:	6073      	str	r3, [r6, #4]
   if (HAL_QSPI_Receive(&QSPIHandle, pData, HAL_QPSI_TIMEOUT_DEFAULT_VALUE) != HAL_OK) {
8049e64:	f7ba f820 	bl	8003ea8 <HAL_QSPI_Receive>
8049e68:	2800      	cmp	r0, #0
8049e6a:	d1ef      	bne.n	8049e4c <BSP_QSPI_Read+0x44>
   MODIFY_REG(QSPIHandle.Instance->DCR, QUADSPI_DCR_CSHT, QSPI_CS_HIGH_TIME_4_CYCLE);
8049e6c:	682a      	ldr	r2, [r5, #0]
8049e6e:	6853      	ldr	r3, [r2, #4]
8049e70:	f423 63e0 	bic.w	r3, r3, #1792	; 0x700
8049e74:	f443 7340 	orr.w	r3, r3, #768	; 0x300
8049e78:	6053      	str	r3, [r2, #4]
}
8049e7a:	b00e      	add	sp, #56	; 0x38
8049e7c:	bd70      	pop	{r4, r5, r6, pc}
8049e7e:	bf00      	nop
8049e80:	20004798 	.word	0x20004798
8049e84:	00000000 	.word	0x00000000

icis4 avatar May 08 '23 11:05 icis4

Stm32CubeIDE 1.12.1, gnu arm-none-eabi 12rel1 -O3

0802e06c <BSP_QSPI_Read>:
 * @param  ReadAddr: Read start address
 * @param  Size: Size of data to read
 * @retval QSPI memory status
 */
uint8_t BSP_QSPI_Read(uint8_t* pData, uint32_t ReadAddr, uint32_t Size)
{
 802e06c:	b530      	push	{r4, r5, lr}
    QSPI_CommandTypeDef s_command;

    /* Initialize the read command */
    s_command.InstructionMode = QSPI_INSTRUCTION_4_LINES;
 802e06e:	f44f 7340 	mov.w	r3, #768	; 0x300
{
 802e072:	b08f      	sub	sp, #60	; 0x3c
    s_command.DdrMode = QSPI_DDR_MODE_DISABLE;
    s_command.DdrHoldHalfCycle = QSPI_DDR_HHC_ANALOG_DELAY;
    s_command.SIOOMode = QSPI_SIOO_INST_EVERY_CMD;

    /* Configure the command */
    if (HAL_QSPI_Command(&QSPIHandle, &s_command, HAL_QPSI_TIMEOUT_DEFAULT_VALUE) != HAL_OK) {
 802e074:	4c1a      	ldr	r4, [pc, #104]	; (802e0e0 <BSP_QSPI_Read+0x74>)
{
 802e076:	4605      	mov	r5, r0
    s_command.InstructionMode = QSPI_INSTRUCTION_4_LINES;
 802e078:	9306      	str	r3, [sp, #24]
    s_command.Instruction = 0xEB;     //QPI_READ_4_BYTE_ADDR_CMD;
 802e07a:	23eb      	movs	r3, #235	; 0xeb
    s_command.Address = ReadAddr;
 802e07c:	9101      	str	r1, [sp, #4]
    s_command.DataMode = QSPI_DATA_4_LINES;
 802e07e:	f04f 7140 	mov.w	r1, #50331648	; 0x3000000
    s_command.Instruction = 0xEB;     //QPI_READ_4_BYTE_ADDR_CMD;
 802e082:	9300      	str	r3, [sp, #0]
    s_command.AddressMode = QSPI_ADDRESS_4_LINES;
 802e084:	f44f 6340 	mov.w	r3, #3072	; 0xc00
    if (HAL_QSPI_Command(&QSPIHandle, &s_command, HAL_QPSI_TIMEOUT_DEFAULT_VALUE) != HAL_OK) {
 802e088:	4620      	mov	r0, r4
    s_command.AddressMode = QSPI_ADDRESS_4_LINES;
 802e08a:	9307      	str	r3, [sp, #28]
    s_command.AddressSize = QSPI_ADDRESS_24_BITS;
 802e08c:	f44f 5300 	mov.w	r3, #8192	; 0x2000
 802e090:	9303      	str	r3, [sp, #12]
    s_command.DataMode = QSPI_DATA_4_LINES;
 802e092:	2300      	movs	r3, #0
 802e094:	e9cd 3108 	strd	r3, r1, [sp, #32]
    s_command.DummyCycles = MX25L128_DUMMY_CYCLES_READ_QUAD_IO;
 802e098:	2108      	movs	r1, #8
    s_command.DdrMode = QSPI_DDR_MODE_DISABLE;
 802e09a:	e9cd 230a 	strd	r2, r3, [sp, #40]	; 0x28
    s_command.DummyCycles = MX25L128_DUMMY_CYCLES_READ_QUAD_IO;
 802e09e:	9105      	str	r1, [sp, #20]
    if (HAL_QSPI_Command(&QSPIHandle, &s_command, HAL_QPSI_TIMEOUT_DEFAULT_VALUE) != HAL_OK) {
 802e0a0:	f241 3288 	movw	r2, #5000	; 0x1388
 802e0a4:	4669      	mov	r1, sp
    s_command.SIOOMode = QSPI_SIOO_INST_EVERY_CMD;
 802e0a6:	e9cd 330c 	strd	r3, r3, [sp, #48]	; 0x30
    if (HAL_QSPI_Command(&QSPIHandle, &s_command, HAL_QPSI_TIMEOUT_DEFAULT_VALUE) != HAL_OK) {
 802e0aa:	f7d5 f97d 	bl	80033a8 <HAL_QSPI_Command>
 802e0ae:	b110      	cbz	r0, 802e0b6 <BSP_QSPI_Read+0x4a>
        return QSPI_ERROR;
 802e0b0:	2001      	movs	r0, #1

    /* Restore S# timing for nonRead commands */
    MODIFY_REG(QSPIHandle.Instance->DCR, QUADSPI_DCR_CSHT, QSPI_CS_HIGH_TIME_4_CYCLE);

    return QSPI_OK;
}
 802e0b2:	b00f      	add	sp, #60	; 0x3c
 802e0b4:	bd30      	pop	{r4, r5, pc}
    MODIFY_REG(QSPIHandle.Instance->DCR, QUADSPI_DCR_CSHT, QSPI_CS_HIGH_TIME_1_CYCLE);
 802e0b6:	6822      	ldr	r2, [r4, #0]
    if (HAL_QSPI_Receive(&QSPIHandle, pData, HAL_QPSI_TIMEOUT_DEFAULT_VALUE) != HAL_OK) {
 802e0b8:	4629      	mov	r1, r5
 802e0ba:	4620      	mov	r0, r4
    MODIFY_REG(QSPIHandle.Instance->DCR, QUADSPI_DCR_CSHT, QSPI_CS_HIGH_TIME_1_CYCLE);
 802e0bc:	6853      	ldr	r3, [r2, #4]
 802e0be:	f423 63e0 	bic.w	r3, r3, #1792	; 0x700
 802e0c2:	6053      	str	r3, [r2, #4]
    if (HAL_QSPI_Receive(&QSPIHandle, pData, HAL_QPSI_TIMEOUT_DEFAULT_VALUE) != HAL_OK) {
 802e0c4:	f241 3288 	movw	r2, #5000	; 0x1388
 802e0c8:	f7d5 fa94 	bl	80035f4 <HAL_QSPI_Receive>
 802e0cc:	2800      	cmp	r0, #0
 802e0ce:	d1ef      	bne.n	802e0b0 <BSP_QSPI_Read+0x44>
    MODIFY_REG(QSPIHandle.Instance->DCR, QUADSPI_DCR_CSHT, QSPI_CS_HIGH_TIME_4_CYCLE);
 802e0d0:	6822      	ldr	r2, [r4, #0]
 802e0d2:	6853      	ldr	r3, [r2, #4]
 802e0d4:	f423 63e0 	bic.w	r3, r3, #1792	; 0x700
 802e0d8:	f443 7340 	orr.w	r3, r3, #768	; 0x300
 802e0dc:	6053      	str	r3, [r2, #4]
    return QSPI_OK;
 802e0de:	e7e8      	b.n	802e0b2 <BSP_QSPI_Read+0x46>
 802e0e0:	2000477c 	.word	0x2000477c

icis4 avatar May 08 '23 12:05 icis4

I think it's above my knowledge level to try and debug that but I suspect this is somehow making the a potential timing issue go away. I'm going to try and dig through some errata today and see if I can reproduce this easier.

Jookia avatar May 08 '23 21:05 Jookia

I dug through errata sheets for the chips the fix currently is applied for and found this in ES0290 which applies to the F74xx and F75xx:

(Begin quote)

2.4.1 Extra data written in the FIFO at the end of a read transfer Description When all the conditions listed below are gathered: • QUADSPI is used in indirect mode. • QUADSPI clock is AHB/2 (PRESCALER = 0x01 in the QUADSPI_CR). • QUADSPI is in quad mode (DMODE = 0b11 in the QUADSPI_CCR). • QUADSPI is in DDR mode (DDRM = 0b1 in the QUADSPI_CCR). • A data is read in the instant when the FIFO buffer gets full at the end of a read transfer, an extra data is unduly written in the FIFO buffer. Workarounds Apply one of the following measures: • Read out the extra data until the BUSY flag goes low, then discard the extra data. • After reading out all the expected received data, set the ABORT bit of the QUADSPI_CR register to flush FIFO and keep the BUSY flag low. The last register configuration is kept.

(End quote)

Looking at the conditions, all of those seem to be set up on my board in Mbed aside from DDR mode. Or being an F47xx or F75xx chip. I'm not sure about the timing.

ES0392, ES0396 ES0445 and for the STM32H7 series include this errata:

(Begin quote)

2.5.1 QUADSPI hangs when QUADSPI_CCR is cleared Description Writing 0x0000 0000 to the QUADSPI_CCR register causes the QUADSPI peripheral to hang while the BUSY flag of the QUADSPI_SR register. remains set. Even an abort does not allow exiting this status. Workaround Clear then set the EN bit in the QUADSPI_CR register.

2.5.2 QUADSPI cannot be used in Indirect read mode when only data phase is activated Description When the QUADSPI is configured in Indirect read with only the data phase activated (in Single, Dual, Quad or Dual-quad I/O mode), the QUADSPI peripheral hangs and the BUSY flag remains of the QUADSPI_SR register remains high. An abort must be performed to reset the BUSY flag and exit from the hanging state. Workaround Insert a dummy phase with at least two dummy cycles.

(End quote)

I tried to trigger 2.5.2 but couldn't. I have no idea what's happening here.

Jookia avatar May 09 '23 06:05 Jookia

I did some more testing today out of curiosity. First, I somewhat minimized the test case to this:

#include "mbed.h"
#include "drivers/QSPI.h"
#include <stdio.h>

int main() {
    QSPI qspi(QSPI_FLASH1_IO0, QSPI_FLASH1_IO1, QSPI_FLASH1_IO2, QSPI_FLASH1_IO3,
                        QSPI_FLASH1_SCK, QSPI_FLASH1_CSN);
    qspi.set_frequency(MBED_CONF_QSPIF_QSPI_FREQ); // prescaler is 26, 40Mhz
    qspi.configure_format(QSPI_CFG_BUS_SINGLE, QSPI_CFG_BUS_SINGLE,
        QSPI_CFG_ADDR_SIZE_24, QSPI_CFG_BUS_QUAD, 8, QSPI_CFG_BUS_QUAD, 4);
    char buffer[4];
    size_t len;
    unsigned long i = 0;
    printf("QSPI test begin\n");
    while(true) {
        len = sizeof(buffer);
        if(i % (1 << 20) == 0)
            printf("read %lu\n", i);
        if(qspi.read(4096, buffer, &len) != QSPI_STATUS_OK)
            printf("err %lu\n", i);
        if(len != 4)
            printf("read %lu len %i\n", i, len);
        ++i;
    }
}

This will reproduce the error after around 45 minutes, or 227,652,225 or so calls. I just added a breakpoint to the error handling for HAL_QSPI_Command.

Interestingly if you remove the set_frequency and configure_format call it will reproduce the error after around 45 minutes still, but it will take 32,889,065 calls. The settings used for QSPI in that case is single bus width, 24 bit address size, no dummy cycles and prescaler of 215 or 5MHz. I don't know what this implies.

When inspecting this bug with my original tests I found the following data dumped from gdb. First data is the QUADSPI_TypeDef, second is the Instance. Remember that each read of the Instance dumps the QSPI registers and reads the FIFO.

Crash 1:

# QSPI reads done, newest to oldest (top is the crash)
$18 = {Instruction = 235, Address = 4179, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 4, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$19 = {Instruction = 235, Address = 0, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 4, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$20 = {Instruction = 235, Address = 4096, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 4, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$21 = {Instruction = 235, Address = 4183, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 8, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$22 = {Instruction = 235, Address = 4179, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 4, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$23 = {Instruction = 235, Address = 4156, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 11, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$24 = {Instruction = 235, Address = 4152, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 4, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$25 = {Instruction = 235, Address = 4167, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 4, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}

# BSP data structure
$30 = {Instance = 0xa0001000, Init = {ClockPrescaler = 26, FifoThreshold = 1, SampleShifting = 16, FlashSize = 30, ChipSelectHighTime = 1024, ClockMode = 0, FlashID = 0, DualFlash = 0}, pTxBuffPtr = 0x200092b1 '\377' <repeats 55 times>, "\220", TxXferSize = 9, TxXferCount = 0, pRxBuffPtr = 0x200023c4 <_main_stack+3628> "", RxXferSize = 4, RxXferCount = 0, hdma = 0x0, Lock = HAL_UNLOCKED, State = HAL_QSPI_STATE_ERROR, ErrorCode = 1, Timeout = 5000}

# QSPI instance, each read reads the FIFO
$32 = {CR = 436207633, DCR = 1967104, SR = 1062, FCR = 0, DLR = 3, CCR = 118549995, AR = 0, ABR = 0, DR = 73, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$33 = {CR = 436207633, DCR = 1967104, SR = 2, FCR = 0, DLR = 3, CCR = 118549995, AR = 0, ABR = 0, DR = 0, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$34 = {CR = 436207633, DCR = 1967104, SR = 2, FCR = 0, DLR = 3, CCR = 118549995, AR = 0, ABR = 0, DR = 0, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$35 = {CR = 436207633, DCR = 1967104, SR = 2, FCR = 0, DLR = 3, CCR = 118549995, AR = 0, ABR = 0, DR = 0, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$36 = {CR = 436207633, DCR = 1967104, SR = 2, FCR = 0, DLR = 3, CCR = 118549995, AR = 0, ABR = 0, DR = 0, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$37 = {CR = 436207633, DCR = 1967104, SR = 2, FCR = 0, DLR = 3, CCR = 118549995, AR = 0, ABR = 0, DR = 0, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}

In this case there is an extra byte in the FIFO after reading 4 bytes. We clear the FIFO threshold of 1 byte by reading 1 byte. This means the FIFO was never full.

Crash 2:

# QSPI reads done, newest to oldest (top is the crash)
$83 = {Instruction = 235, Address = 4112, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 4, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$72 = {Instruction = 235, Address = 4156, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 11, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$73 = {Instruction = 235, Address = 4156, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 11, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$74 = {Instruction = 235, Address = 4096, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 4, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$75 = {Instruction = 235, Address = 4183, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 8, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$76 = {Instruction = 235, Address = 4179, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 4, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$77 = {Instruction = 235, Address = 4156, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 11, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$78 = {Instruction = 235, Address = 4152, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 4, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}

# QSPI instance, each read reads the FIFO
$84 = {CR = 436207633, DCR = 1967104, SR = 2086, FCR = 0, DLR = 7, CCR = 118549995, AR = 0, ABR = 0, DR = 77, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$85 = {CR = 436207633, DCR = 1967104, SR = 1062, FCR = 0, DLR = 7, CCR = 118549995, AR = 0, ABR = 0, DR = 4160688112, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$86 = {CR = 436207633, DCR = 1967104, SR = 2, FCR = 0, DLR = 7, CCR = 118549995, AR = 0, ABR = 0, DR = 0, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$87 = {CR = 436207633, DCR = 1967104, SR = 2, FCR = 0, DLR = 7, CCR = 118549995, AR = 0, ABR = 0, DR = 0, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$88 = {CR = 436207633, DCR = 1967104, SR = 2, FCR = 0, DLR = 7, CCR = 118549995, AR = 0, ABR = 0, DR = 0, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}

In this case after reading 4 bytes we still have an additional 8 bytes in the FIFO.

Crash 3:

# QSPI reads done, newest to oldest (top is the crash)
$38 = {Instruction = 235, Address = 4183, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 8, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$39 = {Instruction = 235, Address = 4096, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 4, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$40 = {Instruction = 235, Address = 4183, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 48, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$41 = {Instruction = 235, Address = 4179, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 4, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$42 = {Instruction = 235, Address = 4183, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 8, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$43 = {Instruction = 235, Address = 4179, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 4, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$44 = {Instruction = 235, Address = 4231, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 64, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$45 = {Instruction = 235, Address = 4167, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 64, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}
$46 = {Instruction = 235, Address = 4156, AlternateBytes = 0, AddressSize = 8192, AlternateBytesSize = 0, DummyCycles = 4, InstructionMode = 256, AddressMode = 3072, AlternateByteMode = 49152, DataMode = 50331648, NbData = 11, DdrMode = 0, DdrHoldHalfCycle = 0, SIOOMode = 0}

# BSP data structure
$50 = {Instance = 0xa0001000, Init = {ClockPrescaler = 26, FifoThreshold = 1, SampleShifting = 16, FlashSize = 30, ChipSelectHighTime = 1024, ClockMode = 0, FlashID = 0, DualFlash = 0}, pTxBuffPtr = 0x200092b1 '\377' <repeats 55 times>, "\220", TxXferSize = 9, TxXferCount = 0, pRxBuffPtr = 0x20009580 "    9\n    10\n", RxXferSize = 48, RxXferCount = 0, hdma = 0x0, Lock = HAL_UNLOCKED, State = HAL_QSPI_STATE_ERROR, ErrorCode = 1, Timeout = 5000}

# QSPI instance, each read reads the FIFO
$52 = {CR = 436207633, DCR = 1967104, SR = 8228, FCR = 0, DLR = 47, CCR = 118549995, AR = 0, ABR = 0, DR = 75, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$53 = {CR = 436207633, DCR = 1967104, SR = 8228, FCR = 0, DLR = 47, CCR = 118549995, AR = 0, ABR = 0, DR = 4160688112, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$54 = {CR = 436207633, DCR = 1967104, SR = 8228, FCR = 0, DLR = 47, CCR = 118549995, AR = 0, ABR = 0, DR = 1953786220, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$55 = {CR = 436207633, DCR = 1967104, SR = 8228, FCR = 0, DLR = 47, CCR = 118549995, AR = 0, ABR = 0, DR = 1936090476, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$56 = {CR = 436207633, DCR = 1967104, SR = 8230, FCR = 0, DLR = 47, CCR = 118549995, AR = 0, ABR = 0, DR = 268492847, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$57 = {CR = 436207633, DCR = 1967104, SR = 7206, FCR = 0, DLR = 47, CCR = 118549995, AR = 0, ABR = 0, DR = 131072, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$58 = {CR = 436207633, DCR = 1967104, SR = 6182, FCR = 0, DLR = 47, CCR = 118549995, AR = 0, ABR = 0, DR = 4096, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$59 = {CR = 436207633, DCR = 1967104, SR = 5158, FCR = 0, DLR = 47, CCR = 118549995, AR = 0, ABR = 0, DR = 16384, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$60 = {CR = 436207633, DCR = 1967104, SR = 4134, FCR = 0, DLR = 47, CCR = 118549995, AR = 0, ABR = 0, DR = 255, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$61 = {CR = 436207633, DCR = 1967104, SR = 3110, FCR = 0, DLR = 47, CCR = 118549995, AR = 0, ABR = 0, DR = 2147483647, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$62 = {CR = 436207633, DCR = 1967104, SR = 2086, FCR = 0, DLR = 47, CCR = 118549995, AR = 0, ABR = 0, DR = 1022, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$63 = {CR = 436207633, DCR = 1967104, SR = 1062, FCR = 0, DLR = 47, CCR = 118549995, AR = 0, ABR = 0, DR = 486285168, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$64 = {CR = 436207633, DCR = 1967104, SR = 2, FCR = 0, DLR = 47, CCR = 118549995, AR = 0, ABR = 0, DR = 0, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$65 = {CR = 436207633, DCR = 1967104, SR = 2, FCR = 0, DLR = 47, CCR = 118549995, AR = 0, ABR = 0, DR = 0, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}

This case is much more complicated. After the driver returns we have a full FIFO and the transfer isn't complete. We have to manually read 48 bytes to get back to a working state. We did 'recently' have a read of 48 bytes, so maybe that bled over?

Crash 4, with the simpler test suite and no quad data:

# BSP data structure
$106 = {handle = {Instance = 0xa0001000, Init = {ClockPrescaler = 215, FifoThreshold = 1, SampleShifting = 16, FlashSize = 30, ChipSelectHighTime = 1024, ClockMode = 0, FlashID = 0, DualFlash = 0}, pTxBuffPtr = 0x0, TxXferSize = 0, TxXferCount = 0, pRxBuffPtr = 0x200021bc <_main_stack+3892> "\004", RxXferSize = 4, RxXferCount = 0, hdma = 0x0, Lock = HAL_UNLOCKED, State = HAL_QSPI_STATE_ERROR, ErrorCode = 1, Timeout = 5000}, qspi = 0, io0 = PC_9, io1 = PC_10, io2 = PE_2, io3 = PD_13, sclk = PB_2, ssel = PB_6}

# QSPI instance, each read reads the FIFO
$108 = {CR = 3607101457, DCR = 1967104, SR = 1062, FCR = 0, DLR = 3, CCR = 83895552, AR = 0, ABR = 0, DR = 0, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}
$109 = {CR = 3607101457, DCR = 1967104, SR = 2, FCR = 0, DLR = 3, CCR = 83895552, AR = 0, ABR = 0, DR = 0, PSMKR = 0, PSMAR = 0, PIR = 0, LPTR = 0}

In this case there's an extra 4 bytes in the FIFO.

Jookia avatar May 10 '23 02:05 Jookia

After running my board overnight with the abort fix used to flush the FIFO I'm pretty sure that's the correct fix. As for whether it's the same errata just triggered differently, I don't know. Something is up the QSPI controller on this chip, and it seems (publicly) undocumented.

Jookia avatar May 11 '23 04:05 Jookia