Re: sd 6:0:0:0: [sdb] Unaligned partial completion
On 06/11/2018 04:08 PM, James Bottomley wrote: On Mon, 2018-06-11 at 14:59 -0700, Ted Cabeen wrote: On 06/11/2018 02:40 PM, James Bottomley wrote: On Mon, 2018-06-11 at 12:20 -0400, Douglas Gilbert wrote: I have also seen Aborted Command sense when doing heavy testing on one or more SAS disks behind a SAS expander. I put it down to a temporary lack of paths available (on the link between the host's HBA and the expander) when one of those SAS disks tries to get a connection back to the host with the data (data-in transfer) from an earlier READ command. In my code (ddpt and sg_dd) I treat it as a "retry" type error and in my experience that works. IOW a follow-up READ with the same parameters is successful. We do treat ABORTED_COMMAND as a retry. However, it will tick down the retry count (usually 3) and then fail if it still occurs. How long does this condition persist for? because if it's long lived we could treat it as ADD_TO_MLQUEUE which would mean we'd retry until the timeout condition was reached. On my system, it's a bit hard to tell, as as soon as ZFS sees the read error, it starts resilvering to repair the sector that reported the I/O error. Without the scrub, it happened once over a 5-day window. During the scrub, it was usually 10s of minutes between occurrences that failed all the retries, but I had some occasions where it happened about 5-10 minutes apart. It definitely seems to be load-related, so how long and hard the load stays elevated is a factor. OK, try this: it will print a rate limited warning if it triggers (showing it is this problem) and return ADD_TO_MLQUEUE for all the SAS errors (we'll likely narrow this if it works, but for now let's do the lot). I replaced the HBA in this system with a new one, and the problem resolved, so this was an intermittent hardware issue, and not software-related. Thanks for digging in with me, it helped a lot to fully understand the software side. --Ted
Re: sd 6:0:0:0: [sdb] Unaligned partial completion
Will do. It'll be a few weeks, as I have to schedule downtime, but I'll
report back my results when it's done.
--Ted
On 06/11/2018 04:08 PM, James Bottomley wrote:
OK, try this: it will print a rate limited warning if it triggers
(showing it is this problem) and return ADD_TO_MLQUEUE for all the SAS
errors (we'll likely narrow this if it works, but for now let's do the
lot).
James
---
diff --git a/drivers/scsi/scsi_error.c b/drivers/scsi/scsi_error.c
index 8932ae81a15a..94aa5cb94064 100644
--- a/drivers/scsi/scsi_error.c
+++ b/drivers/scsi/scsi_error.c
@@ -531,6 +531,11 @@ int scsi_check_sense(struct scsi_cmnd *scmd)
if (sshdr.asc == 0xc1 && sshdr.ascq == 0x01 &&
sdev->sdev_bflags & BLIST_RETRY_ASC_C1)
return ADD_TO_MLQUEUE;
+ if (sshdr.asc == 0x4b) {
+ printk_ratelimited(KERN_WARNING "SAS/SATA link
retry\n");
+ return ADD_TO_MLQUEUE;
+ }
+
return NEEDS_RETRY;
case NOT_READY:
Re: sd 6:0:0:0: [sdb] Unaligned partial completion
On Mon, 2018-06-11 at 14:59 -0700, Ted Cabeen wrote:
> On 06/11/2018 02:40 PM, James Bottomley wrote:
> > On Mon, 2018-06-11 at 12:20 -0400, Douglas Gilbert wrote:
> > > I have also seen Aborted Command sense when doing heavy testing
> > > on one or more SAS disks behind a SAS expander. I put it down to
> > > a temporary lack of paths available (on the link between the
> > > host's HBA and the expander) when one of those SAS disks tries to
> > > get a connection back to the host with the data (data-in
> > > transfer) from an earlier READ command.
> > >
> > > In my code (ddpt and sg_dd) I treat it as a "retry" type error
> > > and in my experience that works. IOW a follow-up READ with the
> > > same parameters is successful.
> >
> > We do treat ABORTED_COMMAND as a retry. However, it will tick down
> > the retry count (usually 3) and then fail if it still occurs. How
> > long does this condition persist for? because if it's long lived we
> > could treat it as ADD_TO_MLQUEUE which would mean we'd retry until
> > the timeout condition was reached.
>
> On my system, it's a bit hard to tell, as as soon as ZFS sees the
> read error, it starts resilvering to repair the sector that reported
> the I/O error. Without the scrub, it happened once over a 5-day
> window. During the scrub, it was usually 10s of minutes between
> occurrences that failed all the retries, but I had some occasions
> where it happened about 5-10 minutes apart. It definitely seems to
> be load-related, so how long and hard the load stays elevated is a
> factor.
OK, try this: it will print a rate limited warning if it triggers
(showing it is this problem) and return ADD_TO_MLQUEUE for all the SAS
errors (we'll likely narrow this if it works, but for now let's do the
lot).
James
---
diff --git a/drivers/scsi/scsi_error.c b/drivers/scsi/scsi_error.c
index 8932ae81a15a..94aa5cb94064 100644
--- a/drivers/scsi/scsi_error.c
+++ b/drivers/scsi/scsi_error.c
@@ -531,6 +531,11 @@ int scsi_check_sense(struct scsi_cmnd *scmd)
if (sshdr.asc == 0xc1 && sshdr.ascq == 0x01 &&
sdev->sdev_bflags & BLIST_RETRY_ASC_C1)
return ADD_TO_MLQUEUE;
+ if (sshdr.asc == 0x4b) {
+ printk_ratelimited(KERN_WARNING "SAS/SATA link
retry\n");
+ return ADD_TO_MLQUEUE;
+ }
+
return NEEDS_RETRY;
case NOT_READY:
Re: sd 6:0:0:0: [sdb] Unaligned partial completion
On 06/11/2018 02:40 PM, James Bottomley wrote: On Mon, 2018-06-11 at 12:20 -0400, Douglas Gilbert wrote: I have also seen Aborted Command sense when doing heavy testing on one or more SAS disks behind a SAS expander. I put it down to a temporary lack of paths available (on the link between the host's HBA and the expander) when one of those SAS disks tries to get a connection back to the host with the data (data-in transfer) from an earlier READ command. In my code (ddpt and sg_dd) I treat it as a "retry" type error and in my experience that works. IOW a follow-up READ with the same parameters is successful. We do treat ABORTED_COMMAND as a retry. However, it will tick down the retry count (usually 3) and then fail if it still occurs. How long does this condition persist for? because if it's long lived we could treat it as ADD_TO_MLQUEUE which would mean we'd retry until the timeout condition was reached. On my system, it's a bit hard to tell, as as soon as ZFS sees the read error, it starts resilvering to repair the sector that reported the I/O error. Without the scrub, it happened once over a 5-day window. During the scrub, it was usually 10s of minutes between occurrences that failed all the retries, but I had some occasions where it happened about 5-10 minutes apart. It definitely seems to be load-related, so how long and hard the load stays elevated is a factor. --Ted
Re: sd 6:0:0:0: [sdb] Unaligned partial completion
[readd linux-scsi] On Mon, 2018-06-11 at 14:43 -0700, Ted Cabeen wrote: > On 06/11/2018 02:40 PM, James Bottomley wrote: > > > I have also seen Aborted Command sense when doing heavy testing > > > on one or more SAS disks behind a SAS expander. I put it down to > > > a temporary lack of paths available (on the link between the > > > host's HBA and the expander) when one of those SAS disks tries to > > > get a connection back to the host with the data (data-in > > > transfer) from an earlier READ command. > > > > > > In my code (ddpt and sg_dd) I treat it as a "retry" type error > > > and in my experience that works. IOW a follow-up READ with the > > > same parameters is successful. > > > > We do treat ABORTED_COMMAND as a retry. However, it will tick down > > the retry count (usually 3) and then fail if it still occurs. How > > long does this condition persist for? because if it's long lived we > > could treat it as ADD_TO_MLQUEUE which would mean we'd retry until > > the timeout condition was reached. > > When you retry, should that result in additional kernel messages, or > does the kernel message only appear after the 3 retrys have all > failed? The latter: without enabling logging, we don't print anything for successfully retried commands. James
Re: sd 6:0:0:0: [sdb] Unaligned partial completion
On Mon, 2018-06-11 at 12:20 -0400, Douglas Gilbert wrote: > On 2018-06-11 12:07 PM, Ted Cabeen wrote: > > I'm seeing a similar behavior on my system, but across multiple > > devices on a SAS drive array (front bays on a Supermicro-based > > system with onboard mpt3sas card). > > The Sense Key here doesn't show a medium error, and the multiple- > > drive behavior makes me think it's more likely either a controller > > or cable problem. Interestingly, the issue only shows up under > > heavy load (specifically a ZFS scrub). > > > > During my next downtime window, I'm going to try to re-create the > > problem while capturing a blktrace. Any other things to try at > > that time, or a filter-mask I should apply? > > > > [Wed Jun 6 14:30:19 2018] blk_update_request: I/O error, dev sdn, > > sector > > 1757633640 > > [Wed Jun 6 14:37:10 2018] sd 15:0:5:0: unaligned partial > > completion avoided > > (xfer_cnt=3072, sector_sz=4096) > > [Wed Jun 6 14:37:10 2018] sd 15:0:5:0: [sdr] FAILED Result: > > hostbyte=DID_OK > > driverbyte=DRIVER_SENSE > > [Wed Jun 6 14:37:10 2018] sd 15:0:5:0: [sdr] Sense Key : Aborted > > Command > > [current] [descriptor] > > [Wed Jun 6 14:37:10 2018] sd 15:0:5:0: [sdr] Add. Sense: Nak > > received > > [Wed Jun 6 14:37:10 2018] sd 15:0:5:0: [sdr] CDB: Read(10) 28 00 > > 07 8a c1 ca 00 > > 00 01 00 > > [Wed Jun 6 14:37:10 2018] blk_update_request: I/O error, dev sdr, > > sector > > 1012272720 > > [Wed Jun 6 15:20:43 2018] sd 15:0:8:0: unaligned partial > > completion avoided > > (xfer_cnt=52224, sector_sz=4096) > > [Wed Jun 6 15:20:43 2018] sd 15:0:8:0: [sdu] FAILED Result: > > hostbyte=DID_OK > > driverbyte=DRIVER_SENSE > > [Wed Jun 6 15:20:43 2018] sd 15:0:8:0: [sdu] Sense Key : Aborted > > Command > > [current] [descriptor] > > [Wed Jun 6 15:20:43 2018] sd 15:0:8:0: [sdu] Add. Sense: Nak > > received > > [Wed Jun 6 15:20:43 2018] sd 15:0:8:0: [sdu] CDB: Read(10) 28 00 > > 12 ab dc 52 00 > > 00 19 00 > > [Wed Jun 6 15:20:43 2018] blk_update_request: I/O error, dev sdu, > > sector > > 2506023568 > > [Wed Jun 6 15:46:20 2018] sd 15:0:2:0: unaligned partial > > completion avoided > > (xfer_cnt=11264, sector_sz=4096) > > [Wed Jun 6 15:46:20 2018] sd 15:0:2:0: [sdo] FAILED Result: > > hostbyte=DID_OK > > driverbyte=DRIVER_SENSE > > [Wed Jun 6 15:46:20 2018] sd 15:0:2:0: [sdo] Sense Key : Aborted > > Command > > [current] [descriptor] > > [Wed Jun 6 15:46:20 2018] sd 15:0:2:0: [sdo] Add. Sense: Nak > > received > > [Wed Jun 6 15:46:20 2018] sd 15:0:2:0: [sdo] CDB: Read(10) 28 00 > > 40 a8 ef b5 00 > > 00 03 00 > > [Wed Jun 6 15:46:20 2018] blk_update_request: I/O error, dev sdo, > > sector > > 8678505896 > > > > I have also seen Aborted Command sense when doing heavy testing on > one or more SAS disks behind a SAS expander. I put it down to a > temporary lack of paths available (on the link between the host's HBA > and the expander) when one of those SAS disks tries to get a > connection back to the host with the data (data-in transfer) from an > earlier READ command. > > In my code (ddpt and sg_dd) I treat it as a "retry" type error and in > my experience that works. IOW a follow-up READ with the same > parameters is successful. We do treat ABORTED_COMMAND as a retry. However, it will tick down the retry count (usually 3) and then fail if it still occurs. How long does this condition persist for? because if it's long lived we could treat it as ADD_TO_MLQUEUE which would mean we'd retry until the timeout condition was reached. James
Re: sd 6:0:0:0: [sdb] Unaligned partial completion
That makes some sense to me. Sathya, Chaitra, and Suganath, is that a change we should consider making to the MPT Fusion Drivers? --Ted On 06/11/2018 09:20 AM, Douglas Gilbert wrote: I have also seen Aborted Command sense when doing heavy testing on one or more SAS disks behind a SAS expander. I put it down to a temporary lack of paths available (on the link between the host's HBA and the expander) when one of those SAS disks tries to get a connection back to the host with the data (data-in transfer) from an earlier READ command. In my code (ddpt and sg_dd) I treat it as a "retry" type error and in my experience that works. IOW a follow-up READ with the same parameters is successful. Doug Gilbert
Re: sd 6:0:0:0: [sdb] Unaligned partial completion
On 2018-06-11 12:07 PM, Ted Cabeen wrote: I'm seeing a similar behavior on my system, but across multiple devices on a SAS drive array (front bays on a Supermicro-based system with onboard mpt3sas card). The Sense Key here doesn't show a medium error, and the multiple-drive behavior makes me think it's more likely either a controller or cable problem. Interestingly, the issue only shows up under heavy load (specifically a ZFS scrub). During my next downtime window, I'm going to try to re-create the problem while capturing a blktrace. Any other things to try at that time, or a filter-mask I should apply? [Wed Jun 6 14:30:19 2018] blk_update_request: I/O error, dev sdn, sector 1757633640 [Wed Jun 6 14:37:10 2018] sd 15:0:5:0: unaligned partial completion avoided (xfer_cnt=3072, sector_sz=4096) [Wed Jun 6 14:37:10 2018] sd 15:0:5:0: [sdr] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [Wed Jun 6 14:37:10 2018] sd 15:0:5:0: [sdr] Sense Key : Aborted Command [current] [descriptor] [Wed Jun 6 14:37:10 2018] sd 15:0:5:0: [sdr] Add. Sense: Nak received [Wed Jun 6 14:37:10 2018] sd 15:0:5:0: [sdr] CDB: Read(10) 28 00 07 8a c1 ca 00 00 01 00 [Wed Jun 6 14:37:10 2018] blk_update_request: I/O error, dev sdr, sector 1012272720 [Wed Jun 6 15:20:43 2018] sd 15:0:8:0: unaligned partial completion avoided (xfer_cnt=52224, sector_sz=4096) [Wed Jun 6 15:20:43 2018] sd 15:0:8:0: [sdu] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [Wed Jun 6 15:20:43 2018] sd 15:0:8:0: [sdu] Sense Key : Aborted Command [current] [descriptor] [Wed Jun 6 15:20:43 2018] sd 15:0:8:0: [sdu] Add. Sense: Nak received [Wed Jun 6 15:20:43 2018] sd 15:0:8:0: [sdu] CDB: Read(10) 28 00 12 ab dc 52 00 00 19 00 [Wed Jun 6 15:20:43 2018] blk_update_request: I/O error, dev sdu, sector 2506023568 [Wed Jun 6 15:46:20 2018] sd 15:0:2:0: unaligned partial completion avoided (xfer_cnt=11264, sector_sz=4096) [Wed Jun 6 15:46:20 2018] sd 15:0:2:0: [sdo] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [Wed Jun 6 15:46:20 2018] sd 15:0:2:0: [sdo] Sense Key : Aborted Command [current] [descriptor] [Wed Jun 6 15:46:20 2018] sd 15:0:2:0: [sdo] Add. Sense: Nak received [Wed Jun 6 15:46:20 2018] sd 15:0:2:0: [sdo] CDB: Read(10) 28 00 40 a8 ef b5 00 00 03 00 [Wed Jun 6 15:46:20 2018] blk_update_request: I/O error, dev sdo, sector 8678505896 I have also seen Aborted Command sense when doing heavy testing on one or more SAS disks behind a SAS expander. I put it down to a temporary lack of paths available (on the link between the host's HBA and the expander) when one of those SAS disks tries to get a connection back to the host with the data (data-in transfer) from an earlier READ command. In my code (ddpt and sg_dd) I treat it as a "retry" type error and in my experience that works. IOW a follow-up READ with the same parameters is successful. Doug Gilbert
Re: sd 6:0:0:0: [sdb] Unaligned partial completion
I'm seeing a similar behavior on my system, but across multiple devices on a SAS drive array (front bays on a Supermicro-based system with onboard mpt3sas card). The Sense Key here doesn't show a medium error, and the multiple-drive behavior makes me think it's more likely either a controller or cable problem. Interestingly, the issue only shows up under heavy load (specifically a ZFS scrub). During my next downtime window, I'm going to try to re-create the problem while capturing a blktrace. Any other things to try at that time, or a filter-mask I should apply? [Wed Jun 6 14:30:19 2018] blk_update_request: I/O error, dev sdn, sector 1757633640 [Wed Jun 6 14:37:10 2018] sd 15:0:5:0: unaligned partial completion avoided (xfer_cnt=3072, sector_sz=4096) [Wed Jun 6 14:37:10 2018] sd 15:0:5:0: [sdr] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [Wed Jun 6 14:37:10 2018] sd 15:0:5:0: [sdr] Sense Key : Aborted Command [current] [descriptor] [Wed Jun 6 14:37:10 2018] sd 15:0:5:0: [sdr] Add. Sense: Nak received [Wed Jun 6 14:37:10 2018] sd 15:0:5:0: [sdr] CDB: Read(10) 28 00 07 8a c1 ca 00 00 01 00 [Wed Jun 6 14:37:10 2018] blk_update_request: I/O error, dev sdr, sector 1012272720 [Wed Jun 6 15:20:43 2018] sd 15:0:8:0: unaligned partial completion avoided (xfer_cnt=52224, sector_sz=4096) [Wed Jun 6 15:20:43 2018] sd 15:0:8:0: [sdu] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [Wed Jun 6 15:20:43 2018] sd 15:0:8:0: [sdu] Sense Key : Aborted Command [current] [descriptor] [Wed Jun 6 15:20:43 2018] sd 15:0:8:0: [sdu] Add. Sense: Nak received [Wed Jun 6 15:20:43 2018] sd 15:0:8:0: [sdu] CDB: Read(10) 28 00 12 ab dc 52 00 00 19 00 [Wed Jun 6 15:20:43 2018] blk_update_request: I/O error, dev sdu, sector 2506023568 [Wed Jun 6 15:46:20 2018] sd 15:0:2:0: unaligned partial completion avoided (xfer_cnt=11264, sector_sz=4096) [Wed Jun 6 15:46:20 2018] sd 15:0:2:0: [sdo] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE [Wed Jun 6 15:46:20 2018] sd 15:0:2:0: [sdo] Sense Key : Aborted Command [current] [descriptor] [Wed Jun 6 15:46:20 2018] sd 15:0:2:0: [sdo] Add. Sense: Nak received [Wed Jun 6 15:46:20 2018] sd 15:0:2:0: [sdo] CDB: Read(10) 28 00 40 a8 ef b5 00 00 03 00 [Wed Jun 6 15:46:20 2018] blk_update_request: I/O error, dev sdo, sector 8678505896
