2023-01-25 08:11:20

by Dhruva Gole

[permalink] [raw]
Subject: [PATCH v2 0/4] STIG Mode Fixes for spi-cadence-qspi driver

* Reset the CMD_CTRL Register, without which read/writes in STIG mode
were failing in some cases. The issue came to light while using STIG
Mode for small reads.
* Also add a flag that can allow us to do direct reads but distinguish
direct writes, thus enabling us to disable writes in DAC mode in some
cases that require it. (Like to write to some connected Flash registers)
* Fix register reads in STIG mode and also use STIG mode while reading flash
registers.
Currently if you try to read a register while in STIG mode there is no
support for ADDR and thus naturally a register never gets read from the
flash.

This patch series has been tested on a TI AM625-SK-EVM with both a quad
spi nor flash (s25hs) and OSPI NOR Flash (s28hs).

Output of ltp-ddt test, "DD_RW_ERASESIZE_UBIFS" run with s25hs512t flash:
...
[ 2.334068] spi-nor spi0.0: s25hs512t (65536 Kbytes)
[ 2.339185] 7 fixed-partitions partitions found on MTD device
fc40000.spi.0
[ 2.346158] Creating 7 MTD partitions on "fc40000.spi.0":
[ 2.351555] 0x000000000000-0x000000080000 : "ospi.tiboot3"
[ 2.358344] 0x000000080000-0x000000280000 : "ospi.tispl"
[ 2.364788] 0x000000280000-0x000000680000 : "ospi.u-boot"
[ 2.371311] 0x000000680000-0x0000006c0000 : "ospi.env"
[ 2.377519] 0x0000006c0000-0x000000700000 : "ospi.env.backup"
[ 2.384419] 0x000000800000-0x000003fc0000 : "ospi.rootfs"
[ 2.390890] 0x000003fc0000-0x000004000000 : "ospi.phypattern"
..snip..
Test Start Time: Wed Jan 11 21:14:31 2023
-----------------------------------------
Testcase Result Exit Value
-------- ------ ----------
OSPI_S_FUNC_DD_RW_ERASESIZE_UBIFS PASS 0

-----------------------------------------------
Total Tests: 1
Total Skipped Tests: 0
Total Failures: 0
Kernel Version: 6.2.0-rc1-00040-g700d796a94e0-dirty
Machine Architecture: aarch64
Hostname: am62xx-evm
...

Previous version link:
https://lore.kernel.org/linux-spi/[email protected]/

Changelog:

* This version addresses concerns from Vaishnav where he was seeing issues
while testing on different platforms.
* Also has additional patches that fix the issues that came to light
while using STIG Mode.

To: Mark Brown <[email protected]>
Cc: Vaishnav Achath <[email protected]>
Cc: Pratyush Yadav <[email protected]>
Cc: Vignesh Raghavendra <[email protected]>

Dhruva Gole (4):
spi: cadence-quadspi: Reset CMD_CTRL Reg on cmd r/w completion
spi: cadence-quadspi: Add flag for direct mode writes
spi: cadence-quadspi: setup ADDR Bits in cmd reads
spi: cadence-quadspi: use STIG mode for small reads

drivers/spi/spi-cadence-quadspi.c | 42 ++++++++++++++++++++++++++++---
1 file changed, 38 insertions(+), 4 deletions(-)

--
2.25.1



2023-01-25 08:11:25

by Dhruva Gole

[permalink] [raw]
Subject: [PATCH v2 3/4] spi: cadence-quadspi: setup ADDR Bits in cmd reads

Setup the Addr bit field while issuing register reads in STIG mode. This
is needed for example flashes like cypress define in their transaction
table that to read any register there is 1 cmd byte and a few more address
bytes trailing the cmd byte. Absence of addr bytes will obviously fail
to read correct data from flash register that maybe requested by flash
driver because the controller doesn't even specify which address of the
flash register the read is being requested from.

Signed-off-by: Dhruva Gole <[email protected]>
---
drivers/spi/spi-cadence-quadspi.c | 11 +++++++++++
1 file changed, 11 insertions(+)

diff --git a/drivers/spi/spi-cadence-quadspi.c b/drivers/spi/spi-cadence-quadspi.c
index 4bbf6e3ad34a..a6d0f1b0bb49 100644
--- a/drivers/spi/spi-cadence-quadspi.c
+++ b/drivers/spi/spi-cadence-quadspi.c
@@ -532,6 +532,17 @@ static int cqspi_command_read(struct cqspi_flash_pdata *f_pdata,
/* 0 means 1 byte. */
reg |= (((n_rx - 1) & CQSPI_REG_CMDCTRL_RD_BYTES_MASK)
<< CQSPI_REG_CMDCTRL_RD_BYTES_LSB);
+
+ /* setup ADDR BIT field */
+ if (op->addr.nbytes) {
+ reg |= (0x1 << CQSPI_REG_CMDCTRL_ADDR_EN_LSB);
+ reg |= ((op->addr.nbytes - 1) &
+ CQSPI_REG_CMDCTRL_ADD_BYTES_MASK)
+ << CQSPI_REG_CMDCTRL_ADD_BYTES_LSB;
+
+ writel(op->addr.val, reg_base + CQSPI_REG_CMDADDRESS);
+ }
+
status = cqspi_exec_flash_cmd(cqspi, reg);
if (status)
return status;
--
2.25.1


2023-01-25 08:11:27

by Dhruva Gole

[permalink] [raw]
Subject: [PATCH v2 4/4] spi: cadence-quadspi: use STIG mode for small reads

Fix the issue where some flash chips like cypress S25HS256T return the
value of the same register over and over in DAC mode.

For example in the TI K3-AM62x Processors refer [0] Technical Reference
Manual there is a layer of digital logic in front of the QSPI/OSPI
Drive when used in DAC mode. This is part of the Flash Subsystem (FSS)
which provides access to external Flash devices.

The FSS0_0_SYSCONFIG Register (Offset = 4h) has a BIT Field for
OSPI_32B_DISABLE_MODE which has a Reset value = 0. This means, OSPI 32bit
mode enabled by default.

Thus, by default controller operates in 32 bit mode causing it to always
align all data to 4 bytes from a 4byte aligned address. In some flash
chips like cypress for example if we try to read some regs in DAC mode
then it keeps sending the value of the first register that was requested
and inorder to read the next reg, we have to stop and re-initiate a new
transaction.

This causes wrong register values to be read than what is desired when
registers are read in DAC mode. Hence if the data.nbytes is very less
then prefer STIG mode for such small reads.

[0] https://www.ti.com/lit/ug/spruiv7a/spruiv7a.pdf

Signed-off-by: Dhruva Gole <[email protected]>
---
drivers/spi/spi-cadence-quadspi.c | 8 +++++++-
1 file changed, 7 insertions(+), 1 deletion(-)

diff --git a/drivers/spi/spi-cadence-quadspi.c b/drivers/spi/spi-cadence-quadspi.c
index a6d0f1b0bb49..2954c06a7f57 100644
--- a/drivers/spi/spi-cadence-quadspi.c
+++ b/drivers/spi/spi-cadence-quadspi.c
@@ -1359,7 +1359,13 @@ static int cqspi_mem_process(struct spi_mem *mem, const struct spi_mem_op *op)
cqspi_configure(f_pdata, mem->spi->max_speed_hz);

if (op->data.dir == SPI_MEM_DATA_IN && op->data.buf.in) {
- if (!op->addr.nbytes)
+ /*
+ * Performing reads in DAC mode forces to read minimum 4 bytes
+ * which is unsupported on some flash devices during register
+ * reads, prefer STIG mode for such small reads.
+ */
+ if (!op->addr.nbytes ||
+ op->data.nbytes <= CQSPI_STIG_DATA_LEN_MAX)
return cqspi_command_read(f_pdata, op);

return cqspi_read(f_pdata, op);
--
2.25.1


2023-02-14 21:11:09

by Mark Brown

[permalink] [raw]
Subject: Re: [PATCH v2 0/4] STIG Mode Fixes for spi-cadence-qspi driver

On Wed, 25 Jan 2023 13:40:19 +0530, Dhruva Gole wrote:
> * Reset the CMD_CTRL Register, without which read/writes in STIG mode
> were failing in some cases. The issue came to light while using STIG
> Mode for small reads.
> * Also add a flag that can allow us to do direct reads but distinguish
> direct writes, thus enabling us to disable writes in DAC mode in some
> cases that require it. (Like to write to some connected Flash registers)
> * Fix register reads in STIG mode and also use STIG mode while reading flash
> registers.
> Currently if you try to read a register while in STIG mode there is no
> support for ADDR and thus naturally a register never gets read from the
> flash.
>
> [...]

Applied to

broonie/spi.git for-next

Thanks!

[1/4] spi: cadence-quadspi: Reset CMD_CTRL Reg on cmd r/w completion
commit: d4f43a2d05faf7febb839edb2e9e8f85dfb9d2d2
[2/4] spi: cadence-quadspi: Add flag for direct mode writes
commit: e8c51b164355c1d519a4b8ad0873f131035d26b7
[3/4] spi: cadence-quadspi: setup ADDR Bits in cmd reads
commit: a8674ae02db232927385c2d0a063e10c0118f5ca
[4/4] spi: cadence-quadspi: use STIG mode for small reads
commit: d403fb6e76bf854ef0f7d84e797e51b9494788e0

All being well this means that it will be integrated into the linux-next
tree (usually sometime in the next 24 hours) and sent to Linus during
the next merge window (or sooner if it is a bug fix), however if
problems are discovered then the patch may be dropped or reverted.

You may get further e-mails resulting from automated or manual testing
and review of the tree, please engage with people reporting problems and
send followup patches addressing any issues that are reported if needed.

If any updates are required or you are submitting further changes they
should be sent as incremental updates against current git, existing
patches will not be replaced.

Please add any relevant lists and maintainers to the CCs when replying
to this mail.

Thanks,
Mark


2023-04-26 02:40:07

by Yoshitaka Ikeda

[permalink] [raw]
Subject: RE: [PATCH v2 4/4] spi: cadence-quadspi: use STIG mode for small reads

Hi Dhruva,

An error occurred in the following environments where this patch was applied, and the flash could not be accessed.
However, after reverting to this patch, it is possible to access it.

- Environment
- OS : Linux 6.3
- SoC : Cyclone V
- Flash : MT25QL512A

- Error at startup
- Kernel log
[ 0.980290] spi-nor spi0.0: found mt25ql512a, expected n25q512a
[ 1.485140] cadence-qspi ff705000.flash: Flash command execution timed out.
[ 1.490792] spi-nor spi0.0: operation failed with -110
[ 1.494654] spi-nor spi0.0: mt25ql512a (65536 Kbytes)

- Error at access
- Access command and log
# hexdump -Cv /dev/mtdblock0
hexdump: /dev/mtdblock0: Input/output error

- Kernel log
[ 2124.201193] cadence-qspi ff705000.flash: QSPI is still busy after 500ms timeout.
[ 2124.201229] spi-nor spi0.0: operation failed with -110
[ 2124.201256] I/O error, dev mtdblock0, sector 0 op 0x0:(READ) flags 0x80700 phys_seg 4 prio class 2
[ 2124.711241] cadence-qspi ff705000.flash: QSPI is still busy after 500ms timeout.
[ 2124.711276] spi-nor spi0.0: operation failed with -110
[ 2124.711302] I/O error, dev mtdblock0, sector 8 op 0x0:(READ) flags 0x80700 phys_seg 3 prio class 2
[ 2125.221193] cadence-qspi ff705000.flash: QSPI is still busy after 500ms timeout.
[ 2125.221230] spi-nor spi0.0: operation failed with -110
[ 2125.221256] I/O error, dev mtdblock0, sector 16 op 0x0:(READ) flags 0x80700 phys_seg 2 prio class 2
[ 2125.731237] cadence-qspi ff705000.flash:. QSPI is still busy after 500ms timeout.
[ 2125.731270] spi-nor spi0.0: operation failed with -110
[ 2125.731296] I/O error, dev mtdblock0, sector 24 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 2
[ 2126.241190] cadence-qspi ff705000.flash:. QSPI is still busy after 500ms timeout.
[ 2126.241224] spi-nor spi0.0: operation failed with -110
[ 2126.241251] I/O error, dev mtdblock0, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2
[ 2126.241274] Buffer I/O error on dev mtdblock0, logical block 0, async page read


regards,
Yoshitaka Ikeda


-----Original Message-----
From: Dhruva Gole <[email protected]>
Sent: Wednesday, January 25, 2023 5:10 PM
To: Mark Brown <[email protected]>
Cc: [email protected]; [email protected]; Vignesh Raghavendra <[email protected]>; Vaishnav Achath <[email protected]>; Dhruva Gole <[email protected]>; [email protected]; [email protected]; [email protected]; Pratyush Yadav <[email protected]>
Subject: [PATCH v2 4/4] spi: cadence-quadspi: use STIG mode for small reads

Fix the issue where some flash chips like cypress S25HS256T return the value of the same register over and over in DAC mode.

For example in the TI K3-AM62x Processors refer [0] Technical Reference Manual there is a layer of digital logic in front of the QSPI/OSPI Drive when used in DAC mode. This is part of the Flash Subsystem (FSS) which provides access to external Flash devices.

The FSS0_0_SYSCONFIG Register (Offset = 4h) has a BIT Field for OSPI_32B_DISABLE_MODE which has a Reset value = 0. This means, OSPI 32bit mode enabled by default.

Thus, by default controller operates in 32 bit mode causing it to always align all data to 4 bytes from a 4byte aligned address. In some flash chips like cypress for example if we try to read some regs in DAC mode then it keeps sending the value of the first register that was requested and inorder to read the next reg, we have to stop and re-initiate a new transaction.

This causes wrong register values to be read than what is desired when registers are read in DAC mode. Hence if the data.nbytes is very less then prefer STIG mode for such small reads.

[0] https://www.ti.com/lit/ug/spruiv7a/spruiv7a.pdf

Signed-off-by: Dhruva Gole <[email protected]>
---
drivers/spi/spi-cadence-quadspi.c | 8 +++++++-
1 file changed, 7 insertions(+), 1 deletion(-)

diff --git a/drivers/spi/spi-cadence-quadspi.c b/drivers/spi/spi-cadence-quadspi.c
index a6d0f1b0bb49..2954c06a7f57 100644
--- a/drivers/spi/spi-cadence-quadspi.c
+++ b/drivers/spi/spi-cadence-quadspi.c
@@ -1359,7 +1359,13 @@ static int cqspi_mem_process(struct spi_mem *mem, const struct spi_mem_op *op)
cqspi_configure(f_pdata, mem->spi->max_speed_hz);

if (op->data.dir == SPI_MEM_DATA_IN && op->data.buf.in) {
- if (!op->addr.nbytes)
+ /*
+ * Performing reads in DAC mode forces to read minimum 4 bytes
+ * which is unsupported on some flash devices during register
+ * reads, prefer STIG mode for such small reads.
+ */
+ if (!op->addr.nbytes ||
+ op->data.nbytes <= CQSPI_STIG_DATA_LEN_MAX)
return cqspi_command_read(f_pdata, op);

return cqspi_read(f_pdata, op);
--
2.25.1

2023-04-26 07:41:32

by Dhruva Gole

[permalink] [raw]
Subject: RE: [PATCH v2 4/4] spi: cadence-quadspi: use STIG mode for small reads

Hi Yoshitaka,

On 26/04/23 08:04, Yoshitaka Ikeda wrote:
> Hi Dhruva,
>
> An error occurred in the following environments where this patch was applied, and the flash could not be accessed.
> However, after reverting to this patch, it is possible to access it.
>
> - Environment
> - OS : Linux 6.3
> - SoC : Cyclone V

Please can you send me the register fields information for the
CQSPI controller used in this device?
I wanted to verify if atall there were any mismatch between the
controller I have tested with vs your SOC's controller.

> - Flash : MT25QL512A
>
> - Error at startup
> - Kernel log
> [ 0.980290] spi-nor spi0.0: found mt25ql512a, expected n25q512a
> [ 1.485140] cadence-qspi ff705000.flash: Flash command execution timed out.
> [ 1.490792] spi-nor spi0.0: operation failed with -110
> [ 1.494654] spi-nor spi0.0: mt25ql512a (65536 Kbytes)
>
> - Error at access
> - Access command and log
> # hexdump -Cv /dev/mtdblock0
> hexdump: /dev/mtdblock0: Input/output error
>
> - Kernel log
> [ 2124.201193] cadence-qspi ff705000.flash: QSPI is still busy after 500ms timeout.
> [ 2124.201229] spi-nor spi0.0: operation failed with -110
> [ 2124.201256] I/O error, dev mtdblock0, sector 0 op 0x0:(READ) flags 0x80700 phys_seg 4 prio class 2
> [ 2124.711241] cadence-qspi ff705000.flash: QSPI is still busy after 500ms timeout.
> [ 2124.711276] spi-nor spi0.0: operation failed with -110
> [ 2124.711302] I/O error, dev mtdblock0, sector 8 op 0x0:(READ) flags 0x80700 phys_seg 3 prio class 2
> [ 2125.221193] cadence-qspi ff705000.flash: QSPI is still busy after 500ms timeout.
> [ 2125.221230] spi-nor spi0.0: operation failed with -110
> [ 2125.221256] I/O error, dev mtdblock0, sector 16 op 0x0:(READ) flags 0x80700 phys_seg 2 prio class 2
> [ 2125.731237] cadence-qspi ff705000.flash:. QSPI is still busy after 500ms timeout.
> [ 2125.731270] spi-nor spi0.0: operation failed with -110
> [ 2125.731296] I/O error, dev mtdblock0, sector 24 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 2
> [ 2126.241190] cadence-qspi ff705000.flash:. QSPI is still busy after 500ms timeout.
> [ 2126.241224] spi-nor spi0.0: operation failed with -110
> [ 2126.241251] I/O error, dev mtdblock0, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2
> [ 2126.241274] Buffer I/O error on dev mtdblock0, logical block 0, async page read
>
>
> regards,
> Yoshitaka Ikeda
>
>
> [..snip..]

It maybe that STIG mode may have some different way of configuring/using
on your SoC.

However at this point it's only a guess and I will wait till I have the
exact information on the controller specs being used in this device
along with the register descriptions.

--
Thanks and Regards,
Dhruva Gole

2023-04-27 00:45:15

by Yoshitaka Ikeda

[permalink] [raw]
Subject: RE: [PATCH v2 4/4] spi: cadence-quadspi: use STIG mode for small reads

Hi Dhruva,

> Please can you send me the register fields information for the CQSPI
> controller used in this device?
> I wanted to verify if atall there were any mismatch between the controller I
> have tested with vs your SOC's controller.

You can find it in the pdf that can be obtained by pressing the download button in the upper right corner of the following website.
- https://www.intel.com/content/www/us/en/docs/programmable/683126/15-0/introduction.html

The description is as follows:
- 15. Quad SPI Flash
- Quad SPI Flash Controller Address Map and Register Definitions

--
Thanks and Regards,
Yoshitaka Ikeda

2023-04-27 13:28:35

by Dhruva Gole

[permalink] [raw]
Subject: RE: [PATCH v2 4/4] spi: cadence-quadspi: use STIG mode for small reads

Hi,

On 27/04/23 06:11, Yoshitaka Ikeda wrote:
> Hi Dhruva,
>
>> Please can you send me the register fields information for the CQSPI
>> controller used in this device?
>> I wanted to verify if atall there were any mismatch between the controller I
>> have tested with vs your SOC's controller.
>
> You can find it in the pdf that can be obtained by pressing the download button in the upper right corner of the following website.
> - https://www.intel.com/content/www/us/en/docs/programmable/683126/15-0/introduction.html

Thanks for sharing, I went through and couldn't really find any major
changes at the controller level.
So I am wondering if some specific sequence of flash operations on your
device is exposing some issues in the driver's STIG reads.


Please can you share some logs with the following patch:
I am trying to see a pattern that may be causing issues.
I am unable to reproduce this on my end at the moment.

...
diff --git a/drivers/spi/spi-cadence-quadspi.c
b/drivers/spi/spi-cadence-quadspi.c
index 6ddb2dfc0f00..5fa71dbd37ef 100644
--- a/drivers/spi/spi-cadence-quadspi.c
+++ b/drivers/spi/spi-cadence-quadspi.c
@@ -1390,6 +1390,14 @@ static int cqspi_exec_mem_op(struct spi_mem *mem,
const struct spi_mem_op *op)
int ret;

ret = cqspi_mem_process(mem, op);
+ /* debug */
+ printk("**********spi_mem_op dump**************");
+ printk("addr: nbytes:0x%X , buswidth 0x%X, dtr 0x%X, val
0x%llX", op->addr.nbytes, op->addr.buswidth, op->addr.dtr, op->addr.val);
+ printk("cmd: nbytes:0x%X , buswidth 0x%X, dtr 0x%X, opcode
0x%X", op->cmd.nbytes, op->cmd.buswidth, op->cmd.dtr, op->cmd.opcode);
+ printk("data: nbytes:0x%X , buswidth 0x%X, dtr 0x%X, data dir
0x%X", op->data.nbytes, op->data.buswidth, op->data.dtr, op->data.dir);
+
+ printk("***************************************");
+ /* ---------------------------- */
if (ret)
dev_err(&mem->spi->dev, "operation failed with %d\n", ret);


...

--
Thanks and Regards,
Dhruva Gole

2023-05-08 01:12:52

by Yoshitaka Ikeda

[permalink] [raw]
Subject: RE: [PATCH v2 4/4] spi: cadence-quadspi: use STIG mode for small reads

Hi Dhruva,

Sorry for the late reply as I was on a long vacation.

> Thanks for sharing, I went through and couldn't really find any major changes
> at the controller level.
> So I am wondering if some specific sequence of flash operations on your
> device is exposing some issues in the driver's STIG reads.

Thank you for looking into this.

> Please can you share some logs with the following patch:
> I am trying to see a pattern that may be causing issues.
> I am unable to reproduce this on my end at the moment.

The logs obtained with the patch applied are as follows:

- Error at startup
- Kernel log
[ 0.980598] **********spi_mem_op dump**************
[ 0.980613] addr: nbytes:0x0 , buswidth 0x0, dtr 0x0, val 0x0
[ 0.984223] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x9F
[ 0.988656] data: nbytes:0x6 , buswidth 0x1, dtr 0x0, data dir 0x1
[ 0.993362] ***************************************
[ 0.998329] spi-nor spi0.0: found mt25ql512a, expected n25q512a
[ 1.006574] **********spi_mem_op dump**************
[ 1.006583] addr: nbytes:0x3 , buswidth 0x1, dtr 0x0, val 0x0
[ 1.010150] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x5A
[ 1.014596] data: nbytes:0x10 , buswidth 0x1, dtr 0x0, data dir 0x1
[ 1.019285] ***************************************
[ 1.524271] cadence-qspi ff705000.flash: Flash command execution timed out.
[ 1.533483] **********spi_mem_op dump**************
[ 1.533489] addr: nbytes:0x3 , buswidth 0x1, dtr 0x0, val 0x10
[ 1.537055] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x5A
[ 1.541579] data: nbytes:0x8 , buswidth 0x1, dtr 0x0, data dir 0x1
[ 1.546266] ***************************************
[ 1.551123] spi-nor spi0.0: operation failed with -110
[ 1.558531] spi-nor spi0.0: mt25ql512a (65536 Kbytes)

- Error at access
- Access command and log
# hexdump -Cv /dev/mtdblock0
hexdump: /dev/mtdblock0: Input/output error

- Kernel log
[ 75.401297] cadence-qspi ff705000.flash: QSPI is still busy after 500ms timeout.
[ 75.401337] **********spi_mem_op dump**************
[ 75.401343] addr: nbytes:0x4 , buswidth 0x1, dtr 0x0, val 0x0
[ 75.401354] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0xC
[ 75.401364] data: nbytes:0x200 , buswidth 0x1, dtr 0x0, data dir 0x1
[ 75.401373] ***************************************
[ 75.401382] spi-nor spi0.0: operation failed with -110
[ 75.401407] I/O error, dev mtdblock0, sector 0 op 0x0:(READ) flags 0x80700 phys_seg 4 prio class 2
[ 75.911339] cadence-qspi ff705000.flash: QSPI is still busy after 500ms timeout.
[ 75.911372] **********spi_mem_op dump**************
[ 75.911379] addr: nbytes:0x4 , buswidth 0x1, dtr 0x0, val 0x1000
[ 75.911390] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0xC
[ 75.911399] data: nbytes:0x200 , buswidth 0x1, dtr 0x0, data dir 0x1
[ 75.911409] ***************************************
[ 75.911417] spi-nor spi0.0: operation failed with -110
[ 75.911443] I/O error, dev mtdblock0, sector 8 op 0x0:(READ) flags 0x80700 phys_seg 3 prio class 2
[ 76.421333] cadence-qspi ff705000.flash: QSPI is still busy after 500ms timeout.
[ 76.421365] **********spi_mem_op dump**************
[ 76.421371] addr: nbytes:0x4 , buswidth 0x1, dtr 0x0, val 0x2000
[ 76.421383] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0xC
[ 76.421393] data: nbytes:0x200 , buswidth 0x1, dtr 0x0, data dir 0x1
[ 76.421403] ***************************************
[ 76.421411] spi-nor spi0.0: operation failed with -110
[ 76.421436] I/O error, dev mtdblock0, sector 16 op 0x0:(READ) flags 0x80700 phys_seg 2 prio class 2
[ 76.931330] cadence-qspi ff705000.flash: QSPI is still busy after 500ms timeout.
[ 76.931365] **********spi_mem_op dump**************
[ 76.931371] addr: nbytes:0x4 , buswidth 0x1, dtr 0x0, val 0x3000
[ 76.931382] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0xC
[ 76.931392] data: nbytes:0x200 , buswidth 0x1, dtr 0x0, data dir 0x1
[ 76.931401] ***************************************
[ 76.931410] spi-nor spi0.0: operation failed with -110
[ 76.931437] I/O error, dev mtdblock0, sector 24 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 2
[ 77.441297] cadence-qspi ff705000.flash: QSPI is still busy after 500ms timeout.
[ 77.441330] **********spi_mem_op dump**************
[ 77.441337] addr: nbytes:0x4 , buswidth 0x1, dtr 0x0, val 0x0
[ 77.441347] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0xC
[ 77.441357] data: nbytes:0x200 , buswidth 0x1, dtr 0x0, data dir 0x1
[ 77.441367] ***************************************
[ 77.441375] spi-nor spi0.0: operation failed with -110
[ 77.441401] I/O error, dev mtdblock0, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2
[ 77.441423] Buffer I/O error on dev mtdblock0, logical block 0, async page read

--
Thanks and Regards,
Yoshitaka Ikeda

2023-05-08 05:48:18

by Dhruva Gole

[permalink] [raw]
Subject: RE: [PATCH v2 4/4] spi: cadence-quadspi: use STIG mode for small reads



On 08/05/23 06:06, Yoshitaka Ikeda wrote:
> Hi Dhruva,
>
> Sorry for the late reply as I was on a long vacation.
>
>> Thanks for sharing, I went through and couldn't really find any major changes
>> at the controller level.
>> So I am wondering if some specific sequence of flash operations on your
>> device is exposing some issues in the driver's STIG reads.
>
> Thank you for looking into this.
>
>> Please can you share some logs with the following patch:
>> I am trying to see a pattern that may be causing issues.
>> I am unable to reproduce this on my end at the moment.
>
> The logs obtained with the patch applied are as follows:

Thanks for sharing the logs. It has made me concerned about something,

>
> - Error at startup
> - Kernel log
> [ 0.980598] **********spi_mem_op dump**************
> [ 0.980613] addr: nbytes:0x0 , buswidth 0x0, dtr 0x0, val 0x0
> [ 0.984223] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x9F
> [ 0.988656] data: nbytes:0x6 , buswidth 0x1, dtr 0x0, data dir 0x1
> [ 0.993362] ***************************************
> [ 0.998329] spi-nor spi0.0: found mt25ql512a, expected n25q512a
> [ 1.006574] **********spi_mem_op dump**************
> [ 1.006583] addr: nbytes:0x3 , buswidth 0x1, dtr 0x0, val 0x0
> [ 1.010150] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x5A
> [ 1.014596] data: nbytes:0x10 , buswidth 0x1, dtr 0x0, data dir 0x1
> [ 1.019285] ***************************************
> [ 1.524271] cadence-qspi ff705000.flash: Flash command execution timed out.

This print message is from cqspi_exec_flash_cmd. This function should
only be called from cqspi_command_read/write .

However, from spi_mem_op dump that you have provided above,
where addr.nbytes is 3 and data.nbytes is 0x10 (which is > 8)
it should never have entered the cqspi_command_read function.

> [ 1.533483] **********spi_mem_op dump**************
> [ 1.533489] addr: nbytes:0x3 , buswidth 0x1, dtr 0x0, val 0x10
> [ 1.537055] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x5A
> [ 1.541579] data: nbytes:0x8 , buswidth 0x1, dtr 0x0, data dir 0x1
> [ 1.546266] ***************************************
> [ 1.551123] spi-nor spi0.0: operation failed with -110
> [ 1.558531] spi-nor spi0.0: mt25ql512a (65536 Kbytes)
>

Anything after the Flash command execution timed out step seems
irrelevant because at that point the controller is in some weird state
that it never again comes out of.


Please can you share the exact output of uname -a where you observe this
error?

I am now wondering why atall would the following conditions be satisfied
in your case:

if (!op->addr.nbytes || op->data.nbytes <= CQSPI_STIG_DATA_LEN_MAX)

either addr.nbytes needs to be 0, which it isn't.
or data has to be <= 8 (which again doesn't seem to be the case here)

So it should never enter the above "if" chunk.

My logs for reference:
https://gist.github.com/DhruvaG2000/7185a84de5757e4988f93478f6b75289


Are you carrying any sort of local patches? Can you make sure that the
CQSPI_STIG_DATA_LEN_MAX is 8 in your case too?
Any other delta from linux-next that I am using in the logs I gave
above?

--
Thanks and Regards,
Dhruva Gole

2023-05-08 08:25:37

by Yoshitaka Ikeda

[permalink] [raw]
Subject: RE: [PATCH v2 4/4] spi: cadence-quadspi: use STIG mode for small reads

Hi Dhruva,

> > - Error at startup
> > - Kernel log
> > [ 0.980598] **********spi_mem_op dump**************
> > [ 0.980613] addr: nbytes:0x0 , buswidth 0x0, dtr 0x0, val 0x0
> > [ 0.984223] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x9F
> > [ 0.988656] data: nbytes:0x6 , buswidth 0x1, dtr 0x0, data dir 0x1
> > [ 0.993362] ***************************************
> > [ 0.998329] spi-nor spi0.0: found mt25ql512a, expected n25q512a
> > [ 1.006574] **********spi_mem_op dump**************
> > [ 1.006583] addr: nbytes:0x3 , buswidth 0x1, dtr 0x0, val 0x0
> > [ 1.010150] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x5A
> > [ 1.014596] data: nbytes:0x10 , buswidth 0x1, dtr 0x0, data dir 0x1
> > [ 1.019285] ***************************************
> > [ 1.524271] cadence-qspi ff705000.flash: Flash command execution
> timed out.
>
> This print message is from cqspi_exec_flash_cmd. This function should only
> be called from cqspi_command_read/write .
>
> However, from spi_mem_op dump that you have provided above, where
> addr.nbytes is 3 and data.nbytes is 0x10 (which is > 8) it should never have
> entered the cqspi_command_read function.

The location of the log output is after the call to cqspi_mem_process(), so I assume it is called with the following data.

[ 1.533483] **********spi_mem_op dump**************
[ 1.533489] addr: nbytes:0x3 , buswidth 0x1, dtr 0x0, val 0x10
[ 1.537055] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x5A
[ 1.541579] data: nbytes:0x8 , buswidth 0x1, dtr 0x0, data dir 0x1
[ 1.546266] ***************************************

Thus, the condition is met and cqspi_command_read() is called.
We have also applied the following patch and confirmed that it is called.

- patch
```
diff --git a/drivers/spi/spi-cadence-quadspi.c b/drivers/spi/spi-cadence-quadspi.c
index 64b6a460d739..8d3681e1f35c 100644
--- a/drivers/spi/spi-cadence-quadspi.c
+++ b/drivers/spi/spi-cadence-quadspi.c
@@ -1365,15 +1365,21 @@ static int cqspi_mem_process(struct spi_mem *mem, const struct spi_mem_op *op)
* reads, prefer STIG mode for such small reads.
*/
if (!op->addr.nbytes ||
- op->data.nbytes <= CQSPI_STIG_DATA_LEN_MAX)
+ op->data.nbytes <= CQSPI_STIG_DATA_LEN_MAX) {
+ printk("----- %d:%s() (1) -----\n", __LINE__, __func__);
return cqspi_command_read(f_pdata, op);
+ }

+ printk("----- %d:%s() (2) -----\n", __LINE__, __func__);
return cqspi_read(f_pdata, op);
}

- if (!op->addr.nbytes || !op->data.buf.out)
+ if (!op->addr.nbytes || !op->data.buf.out) {
+ printk("----- %d:%s() (3) -----\n", __LINE__, __func__);
return cqspi_command_write(f_pdata, op);
+ }

+ printk("----- %d:%s() (4) -----\n", __LINE__, __func__);
return cqspi_write(f_pdata, op);
}

```

- log
```
[ 0.786600] ----- 1369:cqspi_mem_process() (1) -----
[ 0.790312] **********spi_mem_op dump**************
[ 0.790319] addr: nbytes:0x0 , buswidth 0x0, dtr 0x0, val 0x0
[ 0.793885] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x9F
[ 0.798325] data: nbytes:0x6 , buswidth 0x1, dtr 0x0, data dir 0x1
[ 0.803013] ***************************************
[ 0.807892] spi-nor spi0.0: found mt25ql512a, expected n25q512a
[ 0.816062] ----- 1373:cqspi_mem_process() (2) -----
[ 0.819775] **********spi_mem_op dump**************
[ 0.819782] addr: nbytes:0x3 , buswidth 0x1, dtr 0x0, val 0x0
[ 0.823348] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x5A
[ 0.827792] data: nbytes:0x10 , buswidth 0x1, dtr 0x0, data dir 0x1
[ 0.832480] ***************************************
[ 0.837442] ----- 1369:cqspi_mem_process() (1) -----
[ 1.344671] cadence-qspi ff705000.flash: Flash command execution timed out.
[ 1.350328] **********spi_mem_op dump**************
[ 1.350334] addr: nbytes:0x3 , buswidth 0x1, dtr 0x0, val 0x10
[ 1.353901] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x5A
[ 1.358427] data: nbytes:0x8 , buswidth 0x1, dtr 0x0, data dir 0x1
[ 1.363114] ***************************************
[ 1.367981] spi-nor spi0.0: operation failed with -110
[ 1.375376] spi-nor spi0.0: mt25ql512a (65536 Kbytes)
```

> Please can you share the exact output of uname -a where you observe this
> error?

My environment has shortened the output of uname -a, so it may not be useful.
Instead, I will give you information about the kernel I am using.
It is the following (v6.3):
https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux.git/commit/?id=457391b0380335d5e9a5babdec90ac53928b23b4

> Are you carrying any sort of local patches? Can you make sure that the
> CQSPI_STIG_DATA_LEN_MAX is 8 in your case too?

There is no local patch and CQSPI_STIG_DATA_LEN_MAX remains 8.

--
Thanks and Regards,
Yoshitaka Ikeda

2023-05-30 03:12:24

by Yoshitaka Ikeda

[permalink] [raw]
Subject: RE: [PATCH v2 4/4] spi: cadence-quadspi: use STIG mode for small reads

Hi Dhruva,

The patch described below was able to avoid this problem.
However, we could not find any material to determine if it was correct.


Dear all,

Is there anyone else in a similar environment?


```
diff --git a/drivers/spi/spi-cadence-quadspi.c b/drivers/spi/spi-cadence-quadspi.c
index 8f36e1306e16..4a9535e6c86a 100644
--- a/drivers/spi/spi-cadence-quadspi.c
+++ b/drivers/spi/spi-cadence-quadspi.c
@@ -1365,7 +1365,9 @@ static int cqspi_mem_process(struct spi_mem *mem, const struct spi_mem_op *op)
* reads, prefer STIG mode for such small reads.
*/
if (!op->addr.nbytes ||
- op->data.nbytes <= CQSPI_STIG_DATA_LEN_MAX)
+ (op->data.nbytes <= CQSPI_STIG_DATA_LEN_MAX &&
+ !of_device_is_compatible(cqspi->pdev->dev.of_node,
+ "intel,socfpga-qspi")))
return cqspi_command_read(f_pdata, op);

return cqspi_read(f_pdata, op);
```

Thanks and Regards,
Yoshitaka Ikeda



> -----Original Message-----
> From: Yoshitaka Ikeda <[email protected]>
> Sent: Monday, May 8, 2023 4:44 PM
> To: Dhruva Gole <[email protected]>
> Cc: [email protected]; [email protected]; Vignesh
> Raghavendra <[email protected]>; Vaishnav Achath <[email protected]>;
> [email protected]; [email protected];
> [email protected]; Pratyush Yadav <[email protected]>;
> Mark Brown <[email protected]>
> Subject: RE: [PATCH v2 4/4] spi: cadence-quadspi: use STIG mode for small
> reads
>
> Hi Dhruva,
>
> > > - Error at startup
> > > - Kernel log
> > > [ 0.980598] **********spi_mem_op dump**************
> > > [ 0.980613] addr: nbytes:0x0 , buswidth 0x0, dtr 0x0, val 0x0
> > > [ 0.984223] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x9F
> > > [ 0.988656] data: nbytes:0x6 , buswidth 0x1, dtr 0x0, data dir 0x1
> > > [ 0.993362] ***************************************
> > > [ 0.998329] spi-nor spi0.0: found mt25ql512a, expected n25q512a
> > > [ 1.006574] **********spi_mem_op dump**************
> > > [ 1.006583] addr: nbytes:0x3 , buswidth 0x1, dtr 0x0, val 0x0
> > > [ 1.010150] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x5A
> > > [ 1.014596] data: nbytes:0x10 , buswidth 0x1, dtr 0x0, data dir 0x1
> > > [ 1.019285] ***************************************
> > > [ 1.524271] cadence-qspi ff705000.flash: Flash command execution
> > timed out.
> >
> > This print message is from cqspi_exec_flash_cmd. This function should
> > only be called from cqspi_command_read/write .
> >
> > However, from spi_mem_op dump that you have provided above, where
> > addr.nbytes is 3 and data.nbytes is 0x10 (which is > 8) it should
> > never have entered the cqspi_command_read function.
>
> The location of the log output is after the call to cqspi_mem_process(), so I
> assume it is called with the following data.
>
> [ 1.533483] **********spi_mem_op dump************** [ 1.533489] addr:
> nbytes:0x3 , buswidth 0x1, dtr 0x0, val 0x10 [ 1.537055] cmd: nbytes:0x1 ,
> buswidth 0x1, dtr 0x0, opcode 0x5A [ 1.541579] data: nbytes:0x8 , buswidth 0x1,
> dtr 0x0, data dir 0x1 [ 1.546266] ***************************************
>
> Thus, the condition is met and cqspi_command_read() is called.
> We have also applied the following patch and confirmed that it is called.
>
> - patch
> ```
> diff --git a/drivers/spi/spi-cadence-quadspi.c
> b/drivers/spi/spi-cadence-quadspi.c
> index 64b6a460d739..8d3681e1f35c 100644
> --- a/drivers/spi/spi-cadence-quadspi.c
> +++ b/drivers/spi/spi-cadence-quadspi.c
> @@ -1365,15 +1365,21 @@ static int cqspi_mem_process(struct spi_mem
> *mem, const struct spi_mem_op *op)
> * reads, prefer STIG mode for such small reads.
> */
> if (!op->addr.nbytes ||
> - op->data.nbytes <= CQSPI_STIG_DATA_LEN_MAX)
> + op->data.nbytes <= CQSPI_STIG_DATA_LEN_MAX) {
> + printk("----- %d:%s() (1) -----\n", __LINE__,
> __func__);
> return cqspi_command_read(f_pdata, op);
> + }
>
> + printk("----- %d:%s() (2) -----\n", __LINE__, __func__);
> return cqspi_read(f_pdata, op);
> }
>
> - if (!op->addr.nbytes || !op->data.buf.out)
> + if (!op->addr.nbytes || !op->data.buf.out) {
> + printk("----- %d:%s() (3) -----\n", __LINE__, __func__);
> return cqspi_command_write(f_pdata, op);
> + }
>
> + printk("----- %d:%s() (4) -----\n", __LINE__, __func__);
> return cqspi_write(f_pdata, op);
> }
>
> ```
>
> - log
> ```
> [ 0.786600] ----- 1369:cqspi_mem_process() (1) -----
> [ 0.790312] **********spi_mem_op dump**************
> [ 0.790319] addr: nbytes:0x0 , buswidth 0x0, dtr 0x0, val 0x0
> [ 0.793885] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x9F
> [ 0.798325] data: nbytes:0x6 , buswidth 0x1, dtr 0x0, data dir 0x1
> [ 0.803013] ***************************************
> [ 0.807892] spi-nor spi0.0: found mt25ql512a, expected n25q512a
> [ 0.816062] ----- 1373:cqspi_mem_process() (2) -----
> [ 0.819775] **********spi_mem_op dump**************
> [ 0.819782] addr: nbytes:0x3 , buswidth 0x1, dtr 0x0, val 0x0
> [ 0.823348] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x5A
> [ 0.827792] data: nbytes:0x10 , buswidth 0x1, dtr 0x0, data dir 0x1
> [ 0.832480] ***************************************
> [ 0.837442] ----- 1369:cqspi_mem_process() (1) -----
> [ 1.344671] cadence-qspi ff705000.flash: Flash command execution timed
> out.
> [ 1.350328] **********spi_mem_op dump**************
> [ 1.350334] addr: nbytes:0x3 , buswidth 0x1, dtr 0x0, val 0x10
> [ 1.353901] cmd: nbytes:0x1 , buswidth 0x1, dtr 0x0, opcode 0x5A
> [ 1.358427] data: nbytes:0x8 , buswidth 0x1, dtr 0x0, data dir 0x1
> [ 1.363114] ***************************************
> [ 1.367981] spi-nor spi0.0: operation failed with -110
> [ 1.375376] spi-nor spi0.0: mt25ql512a (65536 Kbytes)
> ```
>
> > Please can you share the exact output of uname -a where you observe
> > this error?
>
> My environment has shortened the output of uname -a, so it may not be useful.
> Instead, I will give you information about the kernel I am using.
> It is the following (v6.3):
> https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux.git/commit/?id
> =457391b0380335d5e9a5babdec90ac53928b23b4
>
> > Are you carrying any sort of local patches? Can you make sure that the
> > CQSPI_STIG_DATA_LEN_MAX is 8 in your case too?
>
> There is no local patch and CQSPI_STIG_DATA_LEN_MAX remains 8.
>
> --
> Thanks and Regards,
> Yoshitaka Ikeda