Other Curious SCSI error while zero'ing hard disk

I've re-purposed an old HP X1600 storage server to be used as an archive file server. It has an HP SmartArray P420 in HBA mode and a 12 drive SAS backplane. The drives are 1 TB Western Digital RAID edition disks. As part of making this server suitable again I've started zero'ing all the hard disks. On one of them, during zero'ing, a curious error occured:


Code:
# dd_rescue /dev/zero /dev/da1
dd_rescue: (info): Using softbs=128.0kiB, hardbs=4.0kiB
dd_rescue: (warning): Not using sparse writes for non-seekable output
dd_rescue: (info): ipos: 821438464.0k, opos: 821438464.0k, xferd: 821438464.0k
                   errs:      0, errxfer:         0.0k, succxfer: 821438464.0k
             +curr.rate:    12770kB/s, avg.rate:    13186kB/s, avg.load:-O0.+%
dd_rescue: (warning): write /dev/da1 (821439360.0kiB): Invalid argument
dd_rescue: (warning): assumption rd(131072) == wr(-22) failed!
dd_rescue: (warning): write /dev/da1 (821439359.0kiB): Invalid argument!
dd_rescue: (warning): write /dev/da1 (821439488.0kiB): Invalid argument
dd_rescue: (warning): assumption rd(131072) == wr(-22) failed!
dd_rescue: (warning): write /dev/da1 (821439487.0kiB): Invalid argument!
dd_rescue: (warning): write /dev/da1 (821439616.0kiB): Invalid argument
dd_rescue: (warning): assumption rd(131072) == wr(-22) failed!
dd_rescue: (warning): write /dev/da1 (821439615.0kiB): Invalid argument!
dd_rescue: (info): ipos: 903358464.0k, opos: 903358464.0k, xferd: 903358464.0k
                   errs:      3, errxfer:         0.0k, succxfer: 903358079.9k
             +curr.rate:    12508kB/s, avg.rate:    13119kB/s, avg.load:-O0.+%

The kernel logged the following:

Code:
Dec 14 10:58:38  kernel: (da1:ciss0:32:9:0): WRITE(10). CDB: 2a 00 61 ec 57 00 00 01 00 00
Dec 14 10:58:38  kernel: (da1:ciss0:32:9:0): CAM status: SCSI Status Error
Dec 14 10:58:38  kernel: (da1:ciss0:32:9:0): SCSI status: Check Condition
Dec 14 10:58:38  kernel: (da1:ciss0:32:9:0): SCSI sense: ILLEGAL REQUEST asc:21,0 (Logical block address out of range)
Dec 14 10:58:38  kernel: (da1:ciss0:32:9:0): Error 22, Unretryable error
Dec 14 10:58:45  kernel: (da1:ciss0:32:9:0): WRITE(10). CDB: 2a 00 61 ec 57 00 00 01 00 00
Dec 14 10:58:45  kernel: (da1:ciss0:32:9:0): CAM status: SCSI Status Error
Dec 14 10:58:45  kernel: (da1:ciss0:32:9:0): SCSI status: Check Condition
Dec 14 10:58:45  kernel: (da1:ciss0:32:9:0): SCSI sense: ILLEGAL REQUEST asc:21,0 (Logical block address out of range)
Dec 14 10:58:45  kernel: (da1:ciss0:32:9:0): Error 22, Unretryable error
Dec 14 10:58:52  kernel: (da1:ciss0:32:9:0): WRITE(10). CDB: 2a 00 61 ec 57 00 00 01 00 00
Dec 14 10:58:52  kernel: (da1:ciss0:32:9:0): CAM status: SCSI Status Error
Dec 14 10:58:52  kernel: (da1:ciss0:32:9:0): SCSI status: Check Condition
Dec 14 10:58:52  kernel: (da1:ciss0:32:9:0): SCSI sense: ILLEGAL REQUEST asc:21,0 (Logical block address out of range)
Dec 14 10:58:52  kernel: (da1:ciss0:32:9:0): Error 22, Unretryable error

I've decoded the CDB using this tool, resulting in:

Code:
{ name: 'WRITE (10)',
  fields:
   [ { name: 'OPERATION CODE',
       bits: 8,
       value: '0x2a',
       reserved: false,
       obsolete: false },
     { name: 'Obsolete',
       bits: 1,
       value: '0x0',
       reserved: false,
       obsolete: true },
     { name: 'Obsolete',
       bits: 1,
       value: '0x0',
       reserved: false,
       obsolete: true },
     { name: 'Reserved',
       bits: 1,
       value: '0x0',
       reserved: true,
       obsolete: false },
     { name: 'FUA',
       bits: 1,
       value: '0x0',
       reserved: false,
       obsolete: false },
     { name: 'DPO',
       bits: 1,
       value: '0x0',
       reserved: false,
       obsolete: false },
     { name: 'WRPROTECT',
       bits: 3,
       value: '0x0',
       reserved: false,
       obsolete: false },
     { name: 'LOGICAL BLOCK ADDRESS',
       bits: 32,
       value: '0x61ec5700',
       reserved: false,
       obsolete: false },
     { name: 'GROUP NUMBER',
       bits: 6,
       value: '0x0',
       reserved: false,
       obsolete: false },
     { name: 'Reserved',
       bits: 2,
       value: '0x0',
       reserved: true,
       obsolete: false },
     { name: 'TRANSFER LENGTH',
       bits: 16,
       value: '0x100',
       reserved: false,
       obsolete: false },
     { name: 'CONTROL',
       bits: 8,
       value: '0x0',
       reserved: false,
       obsolete: false } ],
  truncated: false }

If we look at the requested LBA, 0x61ec5700, is 1642878720 in decimal, 1642878720 * 512 = 841 153 904 640, meaning the 841 153 904 640th byte of the disk was being addressed, which is within the size of the disk (1 000 204 886 016 addressable bytes).

So why would the disk (or some other component - the backplane or the controller itself?) report the requested LBA out of range?

FreeBSD version: 11.1-RELEASE-p6
 
Nice CDB decoding tool; never seen it before. Much more convenient than what I always do, which is to decode the CDB by hand.

And your math is completely correct: The CDB calls for writing at sector 0x61 ec 57 00, for 0x01 00 sectors, which is well within the address range of a 1TB disk. The IO size is also sensible: 0x100 = 256 sectors of 512 bytes each is 128KiB, which is what your dd command above report. And the returned sense data (which shows an ASC/ASCQ of 21,0) indeed does indicate "logical block address out of range".

That makes no sense, so we may have to check our assumptions. Question 1: Is this really a 512-byte sector disk? Question 2: Is da1 really the correct disk? I know both questions are long shots. Without some wrong assumption, it must be a bug.

The error most likely comes from the disk itself. Backplanes (meaning SAS expanders) typically don't decode SCSI commands as they come by, and they don't fake sense data going back. I know that some HBAs do occasionally create fake sense data, but for a simple write command that seems unlikely.
 
1) Yeah it really is a 512 byte sector drive. They are HP rebranded Western Digital RE3 drives, with custom firmware from HP.
2) Yes da1 is the correct disk. There are 12 disks of the same type (all WD RE3 1 TB) attached to the controller so can't make a mistake there.

Note that the dd_rescue process continued after the disk reported those LBA's out of range, skipping over those LBA's. I also noticed that at the time the disk was conducting a SMART short test, I'm under the impression that these tests are non-intrusive and should not cause the drive to behave in this way. Here's a dump of the SMART attributes:

Code:
smartctl 6.5 2016-05-07 r4318 [FreeBSD 11.1-RELEASE-p4 amd64] (local build)
Copyright (C) 2002-16, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF INFORMATION SECTION ===
Device Model:     GB1000EAMYC
Serial Number:    WMATV4493599
LU WWN Device Id: 5 0014ee 001d1646c
Firmware Version: HPG6
User Capacity:    1,000,204,886,016 bytes [1.00 TB]
Sector Size:      512 bytes logical/physical
Rotation Rate:    7200 rpm
Device is:        Not in smartctl database [for details use: -P showall]
ATA Version is:   ATA/ATAPI-7 T13/1532D revision 4a
SATA Version is:  SATA 2.5, 3.0 Gb/s
Local Time is:    Thu Dec 14 18:21:04 2017 CET
SMART support is: Available - device has SMART capability.
SMART support is: Enabled

=== START OF READ SMART DATA SECTION ===
SMART overall-health self-assessment test result: PASSED

General SMART Values:
Offline data collection status:  (0x84) Offline data collection activity
                                        was suspended by an interrupting command from host.
                                        Auto Offline Data Collection: Enabled.
Self-test execution status:      (   0) The previous self-test routine completed
                                        without error or no self-test has ever
                                        been run.
Total time to complete Offline
data collection:                (18000) seconds.
Offline data collection
capabilities:                    (0x7b) SMART execute Offline immediate.
                                        Auto Offline data collection on/off support.
                                        Suspend Offline collection upon new
                                        command.
                                        Offline surface scan supported.
                                        Self-test supported.
                                        Conveyance Self-test supported.
                                        Selective Self-test supported.
SMART capabilities:            (0x0003) Saves SMART data before entering
                                        power-saving mode.
                                        Supports SMART auto save timer.
Error logging capability:        (0x01) Error logging supported.
                                        General Purpose Logging supported.
Short self-test routine
recommended polling time:        (   2) minutes.
Extended self-test routine
recommended polling time:        ( 208) minutes.
Conveyance self-test routine
recommended polling time:        (   5) minutes.
SCT capabilities:              (0x303f) SCT Status supported.
                                        SCT Error Recovery Control supported.
                                        SCT Feature Control supported.
                                        SCT Data Table supported.

SMART Attributes Data Structure revision number: 16
Vendor Specific SMART Attributes with Thresholds:
ID# ATTRIBUTE_NAME          FLAG     VALUE WORST THRESH TYPE      UPDATED  WHEN_FAILED RAW_VALUE
  1 Raw_Read_Error_Rate     0x002f   200   200   051    Pre-fail  Always       -       0
  3 Spin_Up_Time            0x0027   253   253   021    Pre-fail  Always       -       1208
  4 Start_Stop_Count        0x0032   100   100   000    Old_age   Always       -       23
  5 Reallocated_Sector_Ct   0x0033   197   197   140    Pre-fail  Always       -       20
  7 Seek_Error_Rate         0x002f   100   253   051    Pre-fail  Always       -       0
  9 Power_On_Hours          0x0032   041   041   000    Old_age   Always       -       43644
 10 Spin_Retry_Count        0x0033   100   253   051    Pre-fail  Always       -       0
 11 Calibration_Retry_Count 0x0033   100   253   051    Pre-fail  Always       -       0
 12 Power_Cycle_Count       0x0032   100   100   000    Old_age   Always       -       23
184 End-to-End_Error        0x0033   100   100   097    Pre-fail  Always       -       0
187 Reported_Uncorrect      0x0032   100   100   000    Old_age   Always       -       0
188 Command_Timeout         0x0032   100   099   000    Old_age   Always       -       1
190 Airflow_Temperature_Cel 0x0022   081   063   045    Old_age   Always       -       19
192 Power-Off_Retract_Count 0x0032   200   200   000    Old_age   Always       -       22
193 Load_Cycle_Count        0x0032   200   200   000    Old_age   Always       -       0
194 Temperature_Celsius     0x0022   131   113   000    Old_age   Always       -       19
196 Reallocated_Event_Count 0x0032   200   200   000    Old_age   Always       -       0
197 Current_Pending_Sector  0x0032   200   200   000    Old_age   Always       -       0
198 Offline_Uncorrectable   0x0030   100   253   000    Old_age   Offline      -       0
199 UDMA_CRC_Error_Count    0x0032   200   200   000    Old_age   Always       -       0
200 Multi_Zone_Error_Rate   0x0008   200   200   000    Old_age   Offline      -       0

SMART Error Log Version: 1
No Errors Logged

SMART Self-test log structure revision number 1
Num  Test_Description    Status                  Remaining  LifeTime(hours)  LBA_of_first_error
# 1  Short offline       Completed without error       00%     43641         -
# 2  Extended offline    Completed without error       00%     43620         -

SMART Selective self-test log data structure revision number 1
 SPAN  MIN_LBA  MAX_LBA  CURRENT_TEST_STATUS
    1        0        0  Not_testing
    2        0        0  Not_testing
    3        0        0  Not_testing
    4        0        0  Not_testing
    5        0        0  Not_testing
Selective self-test flags (0x0):
  After scanning selected spans, do NOT read-scan remainder of disk.
If Selective self-test is pending on power-up, resume after 0 minute delay.

Looks to me the disk is in good health.
 
I once had a similar problem. After long trying out all possible things, finally it turned out that the interface cable was the culprit. It was apparently borderline inbetween good and bad.
So, maybe try another cable...
 
1) Yeah it really is a 512 byte sector drive. They are HP rebranded Western Digital RE3 drives, with custom firmware from HP.
...
I'm under the impression that these tests are non-intrusive and should not cause the drive to behave in this way.
Firmware bug? Although introducing a bug as stupid as the drive returning "address out of range" for a valid sector number would require real talent.

I once had a similar problem. After long trying out all possible things, finally it turned out that the interface cable was the culprit. It was apparently borderline inbetween good and bad.
So, maybe try another cable...
Not a bad idea to try another cable. A friend of mine has a SAS cable sitting on his desk which worked perfectly, until we turned on T10 DIF (hardware checksums), at which point that cable caused the HBA to report that the drive had found checksum errors in the data. This makes no sense, but was repeatable.

While you are messing with random things that should make no difference: Switch drive positions in the JBOD, or try running this drive on a different poiwer supply. What if the power connection is the tiniest bit flakey?
 
Firmware bug? Although introducing a bug as stupid as the drive returning "address out of range" for a valid sector number would require real talent.

That made me laugh.

Seriously though, trying a different cable helps as well as a different power supply. It could be a problem with the connector too. I had a HD failure recently where I finally traced the fault to oxidized metal on the cable connector for the HD itself. I know, right? For HDDs, it's rare to see an electronic failure before something in the mechanism fails (Usually the spindle bearings).
 
Back
Top