Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
Message-ID: <11c63702-cd25-67c9-d0bc-21ec47e14c98@ti.com>
Date:   Mon, 8 May 2023 10:59:21 +0530
MIME-Version: 1.0
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:102.0) Gecko/20100101
 Thunderbird/102.10.0
Subject: RE: [PATCH v2 4/4] spi: cadence-quadspi: use STIG mode for small
 reads
To:     Yoshitaka Ikeda <ikeda@nskint.co.jp>
CC:     "linux-spi@vger.kernel.org" <linux-spi@vger.kernel.org>,
        "linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>,
        Vignesh Raghavendra <vigneshr@ti.com>,
        Vaishnav Achath <vaishnav.a@ti.com>,
        "linux-mtd@lists.infradead.org" <linux-mtd@lists.infradead.org>,
        "linux-arm-kernel@lists.infradead.org" 
        <linux-arm-kernel@lists.infradead.org>,
        "Takahiro.Kuwano@infineon.com" <Takahiro.Kuwano@infineon.com>,
        Pratyush Yadav <ptyadav@amazon.de>,
        Mark Brown <broonie@kernel.org>
References: <20230125081023.1573712-1-d-gole@ti.com>
 <20230125081023.1573712-5-d-gole@ti.com>
 <OSZPR01MB70048CE259A3D63C4179199A8B659@OSZPR01MB7004.jpnprd01.prod.outlook.com>
 <044a723e-b81e-f6f2-8bf7-3680a10abc86@ti.com>
 <OSZPR01MB7004D229048A950C93B40CC88B6A9@OSZPR01MB7004.jpnprd01.prod.outlook.com>
 <b1d30948-ba3d-a4cc-e1ed-851a9dedba7c@ti.com>
 <OSZPR01MB7004907B2FB95F45E9B83FEC8B719@OSZPR01MB7004.jpnprd01.prod.outlook.com>
Content-Language: en-US
From:   Dhruva Gole <d-gole@ti.com>
In-Reply-To: <OSZPR01MB7004907B2FB95F45E9B83FEC8B719@OSZPR01MB7004.jpnprd01.prod.outlook.com>
Content-Type: text/plain; charset="UTF-8"; format=flowed
Content-Transfer-Encoding: 7bit
Precedence: bulk


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