linux-kernel - Re: [RFC PATCH] ata: libata-eh: Retry the cmnd when normal complete occurrd after scsi timeout

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [day] [month] [year] [list]

Message-ID: <Y61cG14nVB8j8Yax@x1-carbon>
Date:   Thu, 29 Dec 2022 09:21:32 +0000
From:   Niklas Cassel <Niklas.Cassel@....com>
To:     Wu Bo <wubo40@...wei.com>
CC:     Damien Le Moal <damien.lemoal@...nsource.wdc.com>,
        "linux-ide@...r.kernel.org" <linux-ide@...r.kernel.org>,
        "linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>,
        "qiuchangqi.qiu@...wei.com" <qiuchangqi.qiu@...wei.com>,
        Wenchao Hao <haowenchao@...wei.com>,
        "chenchunxiao@...wei.com" <chenchunxiao@...wei.com>
Subject: Re: [RFC PATCH] ata: libata-eh: Retry the cmnd when normal complete
 occurrd after scsi timeout

On Thu, Dec 29, 2022 at 11:17:31AM +0800, Wu Bo wrote:
> 
> Hi Niklas,
> 
> Thanks for your detailed reply.
> 
> The case where SCSI timeout wins,
> but there came a normal completion occurred after the SCSI timeout.
> in this scenario, The EH process cannot get the command status
> from the IRQ handler process.
> 
> If the command is not retried, it can only be returned to the upper layer
> with timeout state.

So the possible scenarios are:
1) command completed normally via IRQ handler
2) command completed with error via the IRQ hander

3) SCSI timeout, which is by default 30 seconds. No IRQ came for this specific
   QC for 30 seconds. You should always get a completion for a command
   even if it is error. If the HBA did not send an IRQ for this specific QC
   for 30 seconds, it is obviously misbehaving. libata will reset the HBA,
   and outstanding QCs will be retried.
4) SCSI timeout, so no IRQ came for this specific QC for 30 seconds, so EH gets
   scheduled for this QC, however it takes some milliseconds before the EH
   thread starts running, and then it needs to call the EH ->eh_strategy_handler()
   (ata_scsi_error()) which takes the ap->lock.
   Between the time EH gets scheduled and the ap->lock gets acquired,
   there comes a completion via the IRQ handler that completes the
   command normally.
5) Same as 4) but the IRQ handler completes the command with error.

Note that 4) and 5) are very rare cases.
3) is way more common than 4) and 5).

> 
> Log as fllows:
> sd 1:0:0:0: [sda] tag#30 scsi_eh_1: flush retry cmd, scmd->retries:3,
> scmd->allowed:2
> sd 1:0:0:0: [sda] tag#30 FAILED Result: hostbyte=DID_OK
> driverbyte=DRIVER_TIMEOUT
> sd 1:0:0:0: [sda] tag#30 CDB: Read(10) 28 00 07 5e e6 7b 00 00 01 00
> print_req_error: I/O error, dev sda, sector 123659899

How do you know that this is for scenario 4) ?
You have no prints of the IRQ handler, and the QCs it completed.

To me, it actually looks like scenario 3),
especially since you have "flush retry cmd".

In scenario 3), timed out commands will be retried after the HBA is reset.
Do you see that the HBA gets reset in your log?

If it was scenario 4) or 5) I would have expected a "flush finish cmd"
print instead of a "flush retry cmd" print.

Kind regards,
Niklas