Jump to content
  • 0

SATA issue, drive resets: ataX.00: failed command: READ FPDMA QUEUED


ShadowDance
 Share

Question

This is a continuation of ata1.00: failed command: READ FPDMA QUEUED noted by @djurny. I've experienced the same issue, and have some additional data points to provide.

 

My observations so far:

  • I'm using WDC WD60EFRX (68MYMN1 and 68L0BN1) drives
  • The drives were working without issue previously behind a ASMedia ASM1062 SATA Controller, I've also used some of them behind ASM1542 (external eSATA enclosure)
  • I can reproduce the issue on a clean install of Armbian 20.08.21 Buster and Focal
  • I can reproduce via simple `dd` to `/dev/null` from the drive so filesystem does not seem to be the underlying cause
  • Every drive is affected (i.e. each SATA slot)
  • At what point dd produces an error varies from SATA slot to SATA slot (not drive dependent), SATA slot 4 can reproducibly produce the error almost immediately after starting a read
  • The problem goes away when setting `extraargs=libata.force=3.0` in `/boot/armbianEnv.txt` [1]

[1] However, even with SATA limited to 3 Gbps, the problem did reappear when hot-plugging a drive.

 

This reset happened on drive slot 3 when I hot-plugged a drive onto slot 5. This seems weird to me considering they are supposed to be on different power rails. This may suggest there is in general a problem with either the PSU or power delivery to the drives. Here's an excerpt from the reset:

 

[152957.354311] ata3.00: exception Emask 0x10 SAct 0x80000000 SErr 0x9b0000 action 0xe frozen
[152957.354318] ata3.00: irq_stat 0x00400000, PHY RDY changed
[152957.354322] ata3: SError: { PHYRdyChg PHYInt 10B8B Dispar LinkSeq }
[152957.354328] ata3.00: failed command: READ FPDMA QUEUED
[152957.354335] ata3.00: cmd 60/58:f8:00:f8:e7/01:00:71:02:00/40 tag 31 ncq dma 176128 in
                         res 40/00:f8:00:f8:e7/00:00:71:02:00/40 Emask 0x10 (ATA bus error)
[152957.354338] ata3.00: status: { DRDY }
[152957.354345] ata3: hard resetting link

 

And the full dmesg from when the error happened is below:

 

Spoiler

[152957.354311] ata3.00: exception Emask 0x10 SAct 0x80000000 SErr 0x9b0000 action 0xe frozen
[152957.354318] ata3.00: irq_stat 0x00400000, PHY RDY changed
[152957.354322] ata3: SError: { PHYRdyChg PHYInt 10B8B Dispar LinkSeq }
[152957.354328] ata3.00: failed command: READ FPDMA QUEUED
[152957.354335] ata3.00: cmd 60/58:f8:00:f8:e7/01:00:71:02:00/40 tag 31 ncq dma 176128 in
                         res 40/00:f8:00:f8:e7/00:00:71:02:00/40 Emask 0x10 (ATA bus error)
[152957.354338] ata3.00: status: { DRDY }
[152957.354345] ata3: hard resetting link
[152962.114138] ata4: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[152962.115442] ata4.00: configured for UDMA/133
[152962.334140] ata3: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[152962.335386] ata3.00: configured for UDMA/133
[152962.335438] sd 2:0:0:0: [sdc] tag#31 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08 cmd_age=5s
[152962.335444] sd 2:0:0:0: [sdc] tag#31 Sense Key : 0x5 [current]
[152962.335448] sd 2:0:0:0: [sdc] tag#31 ASC=0x21 ASCQ=0x4
[152962.335454] sd 2:0:0:0: [sdc] tag#31 CDB: opcode=0x88 88 00 00 00 00 02 71 e7 f8 00 00 00 01 58 00 00
[152962.335458] blk_update_request: I/O error, dev sdc, sector 10500962304 op 0x0:(READ) flags 0x700 phys_seg 5 prio class 0
[152962.335477] zio pool=rpool vdev=/dev/mapper/luks-ata-WDC_WD60EFRX-68MYMN1_WD-************-part4 error=5 type=1 offset=5374864261120 size=176128 flags=40080cb0
[152962.335558] ata3: EH complete
[152967.562044] ata5: softreset failed (device not ready)
[152970.353986] ata5: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[152970.354724] ata5.00: ATA-9: WDC WD60EFRX-68L0BN1, 82.00A82, max UDMA/133
[152970.354732] ata5.00: 11721045168 sectors, multi 0: LBA48 NCQ (depth 32), AA
[152970.355605] ata5.00: configured for UDMA/133
[152970.356728] scsi 4:0:0:0: Direct-Access     ATA      WDC WD60EFRX-68L 0A82 PQ: 0 ANSI: 5
[152970.362585] scsi 4:0:0:0: Attached scsi generic sg4 type 0
[152970.367108] sd 4:0:0:0: [sde] 11721045168 512-byte logical blocks: (6.00 TB/5.46 TiB)
[152970.367123] sd 4:0:0:0: [sde] 4096-byte physical blocks
[152970.367150] sd 4:0:0:0: [sde] Write Protect is off
[152970.367154] sd 4:0:0:0: [sde] Mode Sense: 00 3a 00 00
[152970.367185] sd 4:0:0:0: [sde] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[152970.453251]  sde: sde1 sde9
[152970.454796] sd 4:0:0:0: [sde] Attached SCSI disk

 

Edited by ShadowDance
Removed drive serial number from dmesg
Link to comment
Share on other sites

Recommended Posts

  • 0
On 7/25/2021 at 4:40 PM, meymarce said:

However your error is a different one and I cannot see the reset of the SATA connection but if you FS goes into read-only that may indicate another issue.

? The problem begins with a READ FPDMA QUEUED error, and ends with a ro filesystem due to an I/O errors. The result may be different (maybe due to no raid/zfs), but the source looks the same to me.

On 7/25/2021 at 4:40 PM, meymarce said:

Did the drive in slot 4 work after all?

It worked for 8 months without problems, and now it works fine in slot 3. (Where slot 1 is the farthest from the mobo)

 

On 7/25/2021 at 4:40 PM, meymarce said:

If you wanna exchange the cables though: the power os from the original harness, I cut of the data connection part using a separation disk on a rotary tool (Dremel like).

And solder it on the power connectors of the new cables? Hm. I hoped for a simpler solution.

Link to comment
Share on other sites

Help Armbian team helping you

  • 0
3 hours ago, RockBian said:

And solder it on the power connectors of the new cables? Hm. I hoped for a simpler solution.

Nah, no soldering involved. Just cut of the data part of the connector. It destroys that bit irreversibly, but then you are just left with the power connector and you can plug that on the back of new connector

 

image.thumb.png.b6d8f0101f067eab3ee2666bc48ad14d.png

 

I took the assembly image from the wiki and used my amazing paint.net skills to draw lines where to cut; just make sure you leave the power connector intact

 

Link to comment
Share on other sites

  • 0
46 minutes ago, RockBian said:

? The problem begins with a READ FPDMA QUEUED error, and ends with a ro filesystem due to an I/O errors. The result may be different (maybe due to no raid/zfs), but the source looks the same to me.

It does look like the same issue to me and filesystem does not matter, these SATA errors can present themselves simply by reading the disk. And as a result, filesystem corruption is not unexpected, ZFS does protect us from it though.

 

But it can’t be discounted that this could be a disk error as well, perhaps it’s nearing its end-of-life. Which  brand / model of disk do you have?

Link to comment
Share on other sites

  • 0
1 hour ago, ShadowDance said:

Which  brand / model of disk do you have?

# smartctl -a /dev/sdb
smartctl 6.6 2017-11-05 r4594 [aarch64-linux-5.10.35-rockchip64] (local build)
Copyright (C) 2002-17, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF INFORMATION SECTION ===
Device Model:     TOSHIBA HDWD240
Serial Number:    Z9J1S0I9S5HH
LU WWN Device Id: 5 000039 9b560c2c2
Firmware Version: KQ000A
User Capacity:    4,000,787,030,016 bytes [4.00 TB]
Sector Sizes:     512 bytes logical, 4096 bytes physical
Rotation Rate:    5400 rpm
Form Factor:      3.5 inches
Device is:        Not in smartctl database [for details use: -P showall]
ATA Version is:   ACS-3 T13/2161-D revision 5
SATA Version is:  SATA 3.3, 6.0 Gb/s (current: 6.0 Gb/s)
Local Time is:    Mon Jul 26 22:46:35 2021 CEST
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:  (0x00)	Offline data collection activity
					was never started.
					Auto Offline Data Collection: Disabled.
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: 		(  120) seconds.
Offline data collection
capabilities: 			 (0x5b) SMART execute Offline immediate.
					Auto Offline data collection on/off support.
					Suspend Offline collection upon new
					command.
					Offline surface scan supported.
					Self-test supported.
					No 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: 	 ( 502) minutes.
SCT capabilities: 	       (0x003d)	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     0x000b   100   100   050    Pre-fail  Always       -       0
  2 Throughput_Performance  0x0005   100   100   050    Pre-fail  Offline      -       0
  3 Spin_Up_Time            0x0027   100   100   001    Pre-fail  Always       -       8060
  4 Start_Stop_Count        0x0032   100   100   000    Old_age   Always       -       62
  5 Reallocated_Sector_Ct   0x0033   100   100   050    Pre-fail  Always       -       0
  7 Seek_Error_Rate         0x000b   100   100   050    Pre-fail  Always       -       0
  8 Seek_Time_Performance   0x0005   100   100   050    Pre-fail  Offline      -       0
  9 Power_On_Hours          0x0032   078   078   000    Old_age   Always       -       8809
 10 Spin_Retry_Count        0x0033   101   100   030    Pre-fail  Always       -       0
 12 Power_Cycle_Count       0x0032   100   100   000    Old_age   Always       -       10
191 G-Sense_Error_Rate      0x0032   100   100   000    Old_age   Always       -       1
192 Power-Off_Retract_Count 0x0032   100   100   000    Old_age   Always       -       2
193 Load_Cycle_Count        0x0032   100   100   000    Old_age   Always       -       244
194 Temperature_Celsius     0x0022   100   100   000    Old_age   Always       -       18 (Min/Max 12/31)
196 Reallocated_Event_Count 0x0032   100   100   000    Old_age   Always       -       0
197 Current_Pending_Sector  0x0032   100   100   000    Old_age   Always       -       0
198 Offline_Uncorrectable   0x0030   100   100   000    Old_age   Offline      -       0
199 UDMA_CRC_Error_Count    0x0032   200   253   000    Old_age   Always       -       0
220 Disk_Shift              0x0002   100   100   000    Old_age   Always       -       0
222 Loaded_Hours            0x0032   099   099   000    Old_age   Always       -       562
223 Load_Retry_Count        0x0032   100   100   000    Old_age   Always       -       0
224 Load_Friction           0x0022   100   100   000    Old_age   Always       -       0
226 Load-in_Time            0x0026   100   100   000    Old_age   Always       -       803
240 Head_Flying_Hours       0x0001   100   100   001    Pre-fail  Offline      -       0

SMART Error Log Version: 1
ATA Error Count: 3
	CR = Command Register [HEX]
	FR = Features Register [HEX]
	SC = Sector Count Register [HEX]
	SN = Sector Number Register [HEX]
	CL = Cylinder Low Register [HEX]
	CH = Cylinder High Register [HEX]
	DH = Device/Head Register [HEX]
	DC = Device Command Register [HEX]
	ER = Error register [HEX]
	ST = Status register [HEX]
Powered_Up_Time is measured from power on, and printed as
DDd+hh:mm:SS.sss where DD=days, hh=hours, mm=minutes,
SS=sec, and sss=millisec. It "wraps" after 49.710 days.

Error 3 occurred at disk power-on lifetime: 8764 hours (365 days + 4 hours)
  When the command that caused the error occurred, the device was active or idle.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  40 41 98 28 0e c0 40  Error: UNC at LBA = 0x00c00e28 = 12586536

  Commands leading to the command that caused the error were:
  CR FR SC SN CL CH DH DC   Powered_Up_Time  Command/Feature_Name
  -- -- -- -- -- -- -- --  ----------------  --------------------
  60 28 98 10 0e c0 40 00  22d+20:33:25.353  READ FPDMA QUEUED
  ef 10 02 00 00 00 a0 00  22d+20:33:25.353  SET FEATURES [Enable SATA feature]
  27 00 00 00 00 00 e0 00  22d+20:33:25.352  READ NATIVE MAX ADDRESS EXT [OBS-ACS-3]
  ec 00 00 00 00 00 a0 00  22d+20:33:25.352  IDENTIFY DEVICE
  ef 03 45 00 00 00 a0 00  22d+20:33:25.351  SET FEATURES [Set transfer mode]

Error 2 occurred at disk power-on lifetime: 8764 hours (365 days + 4 hours)
  When the command that caused the error occurred, the device was active or idle.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  40 41 28 08 0e c0 40  Error: UNC at LBA = 0x00c00e08 = 12586504

  Commands leading to the command that caused the error were:
  CR FR SC SN CL CH DH DC   Powered_Up_Time  Command/Feature_Name
  -- -- -- -- -- -- -- --  ----------------  --------------------
  60 30 28 08 0e c0 40 00  22d+20:33:22.242  READ FPDMA QUEUED
  60 08 20 60 0d c1 40 00  22d+20:33:22.241  READ FPDMA QUEUED
  60 08 18 78 0d c1 40 00  22d+20:33:22.240  READ FPDMA QUEUED
  60 08 10 70 0d c1 40 00  22d+20:33:22.239  READ FPDMA QUEUED
  60 08 08 68 0d c1 40 00  22d+20:33:22.238  READ FPDMA QUEUED

Error 1 occurred at disk power-on lifetime: 8764 hours (365 days + 4 hours)
  When the command that caused the error occurred, the device was active or idle.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  40 41 28 00 0d c0 40  Error: UNC at LBA = 0x00c00d00 = 12586240

  Commands leading to the command that caused the error were:
  CR FR SC SN CL CH DH DC   Powered_Up_Time  Command/Feature_Name
  -- -- -- -- -- -- -- --  ----------------  --------------------
  60 08 28 00 0d c0 40 00  22d+20:32:39.403  READ FPDMA QUEUED
  60 08 20 80 08 c0 40 00  22d+20:32:39.292  READ FPDMA QUEUED
  60 08 18 10 17 01 40 00  22d+20:32:39.291  READ FPDMA QUEUED
  60 08 10 08 17 01 40 00  22d+20:32:39.290  READ FPDMA QUEUED
  60 08 08 f8 16 01 40 00  22d+20:32:39.289  READ FPDMA QUEUED

SMART Self-test log structure revision number 1
No self-tests have been logged.  [To run self-tests, use: smartctl -t]

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.

 

Link to comment
Share on other sites

  • 0

@RockBian hmm, that output look more like there's a problem with the disk itself. At least none of the SATA errors I've experienced have been logged by the disks themselves, but could be difference in manufacturers. I'd recommend running a short and a long scan (via smartctl) on the disk.

Link to comment
Share on other sites

  • 0

@ShadowDance

SMART Self-test log structure revision number 1
Num  Test_Description    Status                  Remaining  LifeTime(hours)  LBA_of_first_error
# 1  Extended offline    Completed without error       00%      8990         -
# 2  Extended offline    Aborted by host               90%      8974         -
# 3  Extended offline    Aborted by host               90%      8945         -
# 4  Short offline       Completed without error       00%      8944         -

 

It took some time to get the extended offline test completed. Turns out that hdidle aborts it. Anyway, both tests completed without errors, so it seems nothing is wrong with the disk, as the attributes already suggested.

As I can't find a clear description what 'READ FPDMA QUEUED' actually means, I can't say if it's normal that both sides of the SATA bus can detect this error at the same time.

 

 

Link to comment
Share on other sites

  • 0

Yesterday I got a mail from my Kobol that a backup failed, 'mount: /mnt/backup: can't read superblock on /dev/sdb1.'. According to smartctl the disk died. So I ordered a new disk, (a WD red), and today I have put it in the Kobol (hotplug is a bless), in the same slot where the Toshiba was located. The backup is running, and so far no problems.

The problem is, I put the old disk in another box, (a Netgear 104 running Debian), and it's perfectly healthy. At the moment I'm stressing it by running a grep on all files on it (around 1TB), but nothing in dmesg.

 

I used that disk for creating snapshot backups of 2 different sources, one local and one remote, once a week. When looking in dmesg I can see that all backups since beginning this month had a number of 'READ FPDMA QUEUED' errors, followed by a 'hard resetting link', yet all backups succeeded, until yesterday.

 

I'm wondering if it can be a disk incompatibility problem. But in that case it is strange that it worked without problems for half a year.

Link to comment
Share on other sites

  • 0

That sounds now very much like the SATA issues. Source is still unknown apart from the data cables. I could also imagine (hardware noob here) that it may depend on the drive and power draw and signal quality. So maybe the WD is has a better signal quality.

Link to comment
Share on other sites

  • 0

I've bought a molex power cable to use with the new sata cable. But i've not found a sata power cable 8pin(6+2) with the capacitors that came with Helio64.

Do you think that will work?
or It's better to destroy the sata data cable of original cable as @meymarce described?

I'm hoping that this will work. It's sad that we cannot have some spare basic parts of the Helios64

 

 

Screenshot_20211122_110201.png

 

I've bought the following expansion cable to use with the original Helio64 power molex cable 8pin(4+4)
Screenshot_20211126_100751.png.f4e61ad5a1d53005f6542a282d14e079.png

 

Now my helios64 came back to life =D

I was able to complete rebuild the Raid6 and it's working like a charm.

 

The problem is that now I have a lot of cables on the case that was difficult to find an arrangement in a way that I was able to close the case with the fans. The @meymarce solution on splitting the cable is better if you are able to do with confidence not to destroy the power cable.:

Thanks!

Edited by manman
Update cables that works
Link to comment
Share on other sites

  • 0

Hi,

 

I have same problem with WD Red 8to (WDC WD80EFBX-68AZZN0).

In slot 3

Depend of drive, some are more or less sensible

Best configuration without or (with less) error (i test again...) is:

slot 1: WDC WD80EFAX-68KNBN0

slot 2: WDC WD80EFAX-68KNBN0

slot 3: TS256GSSD370S

slot 4: WDC WD80EFBX-68AZZN0

slot 5: WDC WD80EFBX-68AZZN0

 

harddrive in slot 5 was in slot 3 before and i had:

199 UDMA_CRC_Error_Count    0x000a   200   200   000    Old_age   Always       -       11

in:

Error 11 occurred at disk power-on lifetime: 46 hours (1 days + 22 hours)

 

Bye.

Link to comment
Share on other sites

  • 0

@meymarce it’s most likely related, and not due to bad disks. All my disks have received a bunch of UDMA_CRC_Error_Count due to the Helios. I’ve since completely stopped using the Helios and put the same disks inside an ASUSTOR. Zero issues.

 

Basically don’t put WD REDs in a Helios, or be prepared to have a bad time, heh. 

Link to comment
Share on other sites

  • 0
On 11/25/2021 at 10:05 PM, ShadowDance said:

Basically don’t put WD REDs in a Helios, or be prepared to have a bad time, heh. 

As you can read earlier in this thread I had a Toshiba which after half a year acted up in a Helios, while it run fine in another NAS, It's exchanged by a WD Red which is going strong since then. (But it didn't last six months, so far).

Link to comment
Share on other sites

  • 0

@RockBian it wasn’t my intention to color the issue black and white. My statement was based on that most user accounts have been from users of WD REDs. I personally believe this issue is far more prevalent than made out in this thread. It’s simply that triggering the issue may require time and the right kind of workload. So either people don’t trigger the issue or they may not even notice it unless they’re checking system logs.

 

I hope your new disks work out for you. 

 

Either way, I never tried any other disks in my Helios and probably never will considering there’s no further development and Armbian used to break seemingly every other day (a while back). 

Link to comment
Share on other sites

  • 0
On 11/22/2021 at 11:05 AM, manman said:

I've bought a molex power cable to use with the new sata cable. But i've not found a sata power cable 8pin(6+2) with the capacitors that came with Helio64.

Do you think that will work?
or It's better to destroy the sata data cable of original cable as @meymarce described?

I'm hoping that this will work. It's sad that we cannot have some spare basic parts of the Helios64

 

 

Screenshot_20211122_110201.png

 

I've bought the following expansion cable to use with the original Helio64 power molex cable 8pin(4+4)
Screenshot_20211126_100751.png.f4e61ad5a1d53005f6542a282d14e079.png

 

Now my helios64 came back to life =D

I was able to complete rebuild the Raid6 and it's working like a charm.

 

The problem is that now I have a lot of cables on the case that was difficult to find an arrangement in a way that I was able to close the case with the fans. The @meymarce solution on splitting the cable is better if you are able to do with confidence not to destroy the power cable.:

Thanks!


UPDATE:
Even changing the cables, the disks keep failing over time.
I wasn't able to have my NAS running more than a day or two without a failure on the disks. After buying an APC UPS with
Boost and Trim Automatic Voltage Regulation (AVR), my NAS is now running without any failure over more than a week!
So the problem was the unstable energy in my house. Maybe I'll try to put back the original ones to see if it works.

Link to comment
Share on other sites

Join the conversation

You can post now and register later. If you have an account, sign in now to post with your account.
Note: Your post will require moderator approval before it will be visible.

Guest
Answer this question...

×   Pasted as rich text.   Restore formatting

  Only 75 emoji are allowed.

×   Your link has been automatically embedded.   Display as a link instead

×   Your previous content has been restored.   Clear editor

×   You cannot paste images directly. Upload or insert images from URL.

Loading...
 Share

×
×
  • Create New...