Re: [PATCH v5 0/7] libsas and drivers: NCQ error handling

John Garry
2022-10-05T08:53:51Z

On 04/10/2022 15:04, John Garry wrote:
>> Notes unrelated to this patch:
>>
>> Both before and after this series, this driver prints:
>> [ 215.845053] ata21.00: exception Emask 0x0 SAct 0xfc0000 SErr 0x0 action 0x6
>> [ 215.852308] ata21.00: failed command: WRITE FPDMA QUEUED
>> [ 215.857801] ata21.00: cmd 61/00:00:00:3a:d3/01:00:b3:04:00/40 tag 18 ncq dma 131072 out
>> res 43/04:00:ff:3a:d3/00:00:b3:04:00/40 Emask 0x400 (NCQ error) <F>
>> [ 215.874396] ata21.00: status: { DRDY SENSE ERR }
>> [ 215.879192] ata21.00: error: { ABRT }
>> [ 215.882997] ata21.00: failed command: WRITE FPDMA QUEUED
>> [ 215.888479] ata21.00: cmd 61/00:00:00:3b:d3/01:00:b3:04:00/40 tag 19 ncq dma 131072 out
>> res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
>> [ 215.904814] ata21.00: failed command: WRITE FPDMA QUEUED
>> [ 215.910311] ata21.00: cmd 61/00:00:00:3c:d3/01:00:b3:04:00/40 tag 20 ncq dma 131072 out
>> res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
>> [ 215.932679] ata21.00: failed command: WRITE FPDMA QUEUED
>> [ 215.941203] ata21.00: cmd 61/00:00:00:3d:d3/01:00:b3:04:00/40 tag 21 ncq dma 131072 out
>> res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
>> [ 215.963616] ata21.00: failed command: WRITE FPDMA QUEUED
>> [ 215.972150] ata21.00: cmd 61/00:00:00:3e:d3/01:00:b3:04:00/40 tag 22 ncq dma 131072 out
>> res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
>> [ 215.994532] ata21.00: failed command: WRITE FPDMA QUEUED
>> [ 216.003124] ata21.00: cmd 61/00:00:00:3f:d3/01:00:b3:04:00/40 tag 23 ncq dma 131072 out
>> res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
>>
>> HSM (Host State Machine) violation errors.
>>
>> For the same SATA drive connected via AHCI this will instead give:
>>
>> [ 3796.944923] ata14.00: exception Emask 0x0 SAct 0x80800003 SErr 0xc0000 action 0x0
>> [ 3796.959375] ata14.00: irq_stat 0x40000008
>> [ 3796.970140] ata14: SError: { CommWake 10B8B }
>> [ 3796.981231] ata14.00: failed command: WRITE FPDMA QUEUED
>> [ 3796.993237] ata14.00: cmd 61/00:08:00:7e:73/02:00:8e:08:00/40 tag 1 ncq dma 262144 out
>> res 43/04:01:00:00:00/00:00:00:00:00/40 Emask 0x1 (device error)
>> [ 3797.017984] ata14.00: status: { DRDY SENSE ERR }
>> [ 3797.026833] ata14.00: error: { ABRT }
>> [ 3797.034664] ata14.00: failed command: WRITE FPDMA QUEUED
>> [ 3797.043015] ata14.00: cmd 61/00:b8:00:60:73/0a:00:8e:08:00/40 tag 23 ncq dma 1310720 out
>> res 43/04:00:df:67:73/00:00:8e:08:00/40 Emask 0x400 (NCQ error) <F>
>> [ 3797.065224] ata14.00: status: { DRDY SENSE ERR }
>> [ 3797.072914] ata14.00: error: { ABRT }
>> [ 3797.079598] ata14.00: failed command: WRITE FPDMA QUEUED
>> [ 3797.087920] ata14.00: cmd 61/00:f8:00:6a:73/0a:00:8e:08:00/40 tag 31 ncq dma 1310720 out
>> res 43/04:00:00:00:00/00:00:00:00:00/00 Emask 0x1 (device error)
>> [ 3797.109800] ata14.00: status: { DRDY SENSE ERR }
>> [ 3797.117451] ata14.00: error: { ABRT }
>>
>> device error errors.
>>
>>
>> Except for the I/O that caused the NCQ error, the remaining outstanding I/Os,
>> regardless if they were aborted by the drive, as a side-effect of reading the
>> NCQ error log (see 13.7.4 Queued Error Log (10h) in SATA 3.5a spec),
>> or if they were aborted by the host (by sas_ata_device_link_abort()),
>> I don't think it is correct to report these as HSM violation errors.
>>
>> HSM violation errors are e.g. when you try to issue a command to a drive
>> that has ATA_BUSY bit set.
> We had a similar issue for hisi_sas and solved in patch 4/7: don't set
> ATA_ERR in the fis for those IO which complete with error, but abort the
> IO via sas_abort_task().
>
> For pm80xx the IO is either rejected (actually completes with rejection)
> or is aborted via internal abort command. Maybe we can do similar for
> pm8001 as we allow the IO to complete in both cases with error. I'll check.

Hi Niklas,

Could you try a change like this on top:

void sas_ata_device_link_abort(struct domain_device *device, bool
force_reset)
{
struct ata_port *ap = device->sata_dev.ap;
struct ata_link *link = &ap->link;

+ device->sata_dev.fis[2] = ATA_ERR | ATA_DRDY;
+ device->sata_dev.fis[3] = 0x04;

link->eh_info.err_mask |= AC_ERR_DEV;
if (force_reset)
link->eh_info.action |= ATA_EH_RESET;
ata_link_abort(link);
}
EXPORT_SYMBOL_GPL(sas_ata_device_link_abort);

I tried it myself and it looked to work ok, except I have a problem with
my arm64 system in that the read log ext times-out and all TF show
"device error", like:

[ 350.257870] ata1.00: qc timeout (cmd 0x47)
[ 350.262054] pm80xx0:: mpi_sata_completion 2293: task null, freeing
CCB tag 2
[ 350.269128] ata1.00: Read log 0x10 page 0x00 failed, Emask 0x40

[ 350.281581] ata1: failed to read log page 10h (errno=-5)
[ 350.577181] ata1.00: exception Emask 0x1 SAct 0xffffffff SErr 0x0
action 0x6 frozen
[ 350.584836] ata1.00: failed command: READ FPDMA QUEUED
[ 350.589970] ata1.00: cmd 60/00:00:80:26:00/01:00:00:00:00/40 tag 0
ncq dma 131072 in
res 41/04:00:00:00:00/00:00:00:00:00/00 Emask 0x1 (device
error)
[ 350.605533] ata1.00: status: { DRDY ERR }
[ 350.609541] ata1.00: error: { ABRT }
[ 350.613115] ata1.00: failed command: READ FPDMA QUEUED
[ 350.618248] ata1.00: cmd 60/00:00:80:26:00/01:00:00:00:00/40 tag 1
ncq dma 131072 in
res 41/04:00:00:00:00/00:00:00:00:00/00 Emask 0x1 (device
error)
[ 350.633809] ata1.00: status: { DRDY ERR
[ 350.637813] ata1.00: error: { ABRT }
[ 350.641384] ata1.00: failed command: READ FPDMA QUEUED
[ 350.646515] ata1.00: cmd 60/00:00:80:26:00/01:00:00:00:00/40 tag 2
ncq dma 131072 in
res 41/04:00:00:00:00/00:00:00:00:00/00 Emask 0x1 (device
error)
[ 350.662076] ata1.00: status: { DRDY ERR
[ 350.666080] ata1.00: error: { ABRT }
[ 350.669652] ata1.00: failed command: READ FPDMA QUEUED
[ 350.674784] ata1.00: cmd 60/00:00:d8:26:00/01:00:00:00:00/40 tag 3
ncq dma 131072 in
res 41/04:00:00:00:00/00:00:00:00:00/00 Emask 0x1 (device
error)
[ 350.690344] ata1.00: status: { DRDY ERR
[ 350.694348] ata1.00: error: { ABRT }
[ 350.697919] ata1.00: failed command: READ FPDMA QUEUED
[ 350.703051] ata1.00: cmd 60/00:00:e0:26:00/01:00:00:00:00/40 tag 4
ncq dma 131072 in
res 41/04:00:00:00:00/00:00:00:00:00/00 Emask 0x1 (device
error)
[ 350.718612] ata1.00: status: { DRDY ERR
[ 350.722623] ata1.00: error: { ABRT }
[ 350.726196] ata1.00: failed command: READ FPDMA QUEUED
[ 350.731329] ata1.00: cmd 60/00:00:c8:26:00/01:00:00:00:00/40 tag 5
ncq dma 131072 in
res 41/04:00:00:00:00/00:00:00:00:00/00 Emask 0x1 (device
error)

...

Thanks,
John