Re: [PATCH 0/2] Improve ATA NCQ command error in mpt3sas and mpi3mr

[Damien Le Moal <dlemoal@kernel.org>]

On 6/11/25 12:27 PM, Yafang Shao wrote:
> On Mon, Jun 9, 2025 at 3:18 PM Damien Le Moal <dlemoal@kernel.org> wrote:
>>
>> On 6/9/25 16:09, Yafang Shao wrote:
>>> On Mon, Jun 9, 2025 at 1:50 PM Christoph Hellwig <hch@infradead.org> wrote:
>>>>
>>>> Adding Yafang Shao <laoar.shao@gmail.com>, who has a test case, which
>>>> I think promted this.
>>
>> Note that cdl-tools test suite has many test cases that do not pass without the
>> mpi3mr patch. CDL makes it easy to trigger the issue.
>>
>>>
>>> Thank you for the information and for addressing this so quickly!
>>>
>>>>
>>>> Yafang, can you check if this makes the writeback errors you're seeing
>>>> go away?
>>>
>>> I’m happy to test the fix and will share the results as soon as I have them.
>>
>> Thanks. And my apologies for forgetting to CC you on these patches.
> 
> We have developed and deployed a hotfix to hundreds of our production
> servers equipped with this drive, and it has been functioning as
> expected so far. We are currently rolling it out to the remaining
> production servers, though the process may take some time to complete.
> 
> Additionally, we encountered a writeback error in the libata driver,
> which appears to be related to DID_TIME_OUT. Do you have any insights
> into this issue?
> 
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#30 FAILED Result:
> hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK cmd_age=31s

No idea. Timeout is hard to debug... A bus trace would help. It could be that
the drives are really bad and taking too long per command, thus causing time
out for commands that are at the end of the queue. E.g., if you hit many bad
sectors with read commands, the drive internal retry mechanism may cause such
read command to take several seconds. So if you are running the drives at high
queue depth, this can easily cause timeouts for the commands that are at the
end of the queue.

> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#30 CDB: Write(16) 8a
> 00 00 00 00 08 2c eb 4a 58 00 00 02 c0 00 00
> [Tue Jun 10 13:27:47 2025] I/O error, dev sdl, sector 35113355864 op
> 0x1:(WRITE) flags 0x100000 phys_seg 88 prio class 2
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#29 FAILED Result:
> hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK cmd_age=31s
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#29 CDB: Write(16) 8a
> 00 00 00 00 08 2c eb 45 18 00 00 05 40 00 00
> [Tue Jun 10 13:27:47 2025] I/O error, dev sdl, sector 35113354520 op
> 0x1:(WRITE) flags 0x104000 phys_seg 168 prio class 2
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#28 FAILED Result:
> hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK cmd_age=31s
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#28 CDB: Write(16) 8a
> 00 00 00 00 08 2c eb 42 58 00 00 02 c0 00 00
> [Tue Jun 10 13:27:47 2025] I/O error, dev sdl, sector 35113353816 op
> 0x1:(WRITE) flags 0x100000 phys_seg 88 prio class 2
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#22 FAILED Result:
> hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK cmd_age=31s
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#22 CDB: Read(16) 88
> 00 00 00 00 03 d8 33 44 18 00 00 02 c0 00 00
> [Tue Jun 10 13:27:47 2025] I/O error, dev sdl, sector 16512140312 op
> 0x0:(READ) flags 0x80700 phys_seg 88 prio class 2
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#21 FAILED Result:
> hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK cmd_age=31s
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#21 CDB: Read(16) 88
> 00 00 00 00 03 d8 33 3e d8 00 00 05 40 00 00
> [Tue Jun 10 13:27:47 2025] I/O error, dev sdl, sector 16512138968 op
> 0x0:(READ) flags 0x84700 phys_seg 168 prio class 2
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#20 FAILED Result:
> hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK cmd_age=31s
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#20 CDB: Read(16) 88
> 00 00 00 00 03 d8 33 3c 18 00 00 02 c0 00 00
> [Tue Jun 10 13:27:47 2025] I/O error, dev sdl, sector 16512138264 op
> 0x0:(READ) flags 0x80700 phys_seg 88 prio class 2
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#19 FAILED Result:
> hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK cmd_age=31s
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#19 CDB: Write(16) 8a
> 00 00 00 00 08 2c eb 3d 18 00 00 05 40 00 00
> [Tue Jun 10 13:27:47 2025] I/O error, dev sdl, sector 35113352472 op
> 0x1:(WRITE) flags 0x104000 phys_seg 168 prio class 2
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#15 FAILED Result:
> hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK cmd_age=31s
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#15 CDB: Read(16) 88
> 00 00 00 00 03 2c e9 4e b8 00 00 00 98 00 00
> [Tue Jun 10 13:27:47 2025] I/O error, dev sdl, sector 13638389432 op
> 0x0:(READ) flags 0x80700 phys_seg 19 prio class 2
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#14 FAILED Result:
> hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK cmd_age=31s
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#14 CDB: Read(16) 88
> 00 00 00 00 03 2c e9 4c b8 00 00 02 00 00 00
> [Tue Jun 10 13:27:47 2025] I/O error, dev sdl, sector 13638388920 op
> 0x0:(READ) flags 0x80700 phys_seg 64 prio class 2
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#13 FAILED Result:
> hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK cmd_age=31s
> [Tue Jun 10 13:27:47 2025] sd 14:0:0:0: [sdl] tag#13 CDB: Read(16) 88
> 00 00 00 00 03 d8 33 36 d8 00 00 05 40 00 00
> [Tue Jun 10 13:27:47 2025] I/O error, dev sdl, sector 16512136920 op
> 0x0:(READ) flags 0x84700 phys_seg 168 prio class 2
> [Tue Jun 10 13:27:47 2025] XFS (sdl): metadata I/O error in
> "xfs_imap_to_bp+0x4f/0x70 [xfs]" at daddr 0x4804c4398 len 32 error 5
> [Tue Jun 10 13:27:48 2025] sdl: writeback error on inode 32213499599,
> offset 0, sector 35113332208
> 


-- 
Damien Le Moal
Western Digital Research