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

From: Yoshitaka Ikeda
Date: Sun May 07 2023 - 20:36:16 EST


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