System crashed - ATA errors

HannesJo · Jul 4th 2023

Hi everyone,

today in the morning my system crashed. After rebooting I found nothing special in the logs but just recognized the latest entries. Seems to be storage related but I could need some advice what they mean exactly. Storage controller, cable, hard drive dying? Thanks in advance!

Code

...
Jul  4 12:40:01 nas kernel: [ 7675.155130] ata2.00: exception Emask 0x50 SAct 0x2 SErr 0x4090800 action 0xe frozen
Jul  4 12:40:01 nas kernel: [ 7675.155176] ata2.00: irq_stat 0x00400040, connection status changed
Jul  4 12:40:01 nas kernel: [ 7675.155202] ata2: SError: { HostInt PHYRdyChg 10B8B DevExch }
Jul  4 12:40:01 nas kernel: [ 7675.155228] ata2.00: failed command: READ FPDMA QUEUED
Jul  4 12:40:01 nas kernel: [ 7675.155252] ata2.00: cmd 60/38:08:c8:66:61/00:00:98:01:00/40 tag 1 ncq dma 28672 in
Jul  4 12:40:01 nas kernel: [ 7675.155252]          res 40/00:08:c8:66:61/00:00:98:01:00/40 Emask 0x50 (ATA bus error)
Jul  4 12:40:01 nas kernel: [ 7675.155312] ata2.00: status: { DRDY }
Jul  4 12:40:01 nas kernel: [ 7675.155330] ata2: hard resetting link
Jul  4 12:40:01 nas kernel: [ 7675.179119] ata3.00: exception Emask 0x10 SAct 0x2 SErr 0x40d0002 action 0xe frozen
Jul  4 12:40:01 nas kernel: [ 7675.179167] ata3.00: irq_stat 0x00400000, PHY RDY changed
Jul  4 12:40:01 nas kernel: [ 7675.179191] ata3: SError: { RecovComm PHYRdyChg CommWake 10B8B DevExch }
Jul  4 12:40:01 nas kernel: [ 7675.179218] ata3.00: failed command: READ FPDMA QUEUED
Jul  4 12:40:01 nas kernel: [ 7675.179243] ata3.00: cmd 60/10:08:00:c7:60/00:00:98:01:00/40 tag 1 ncq dma 8192 in
Jul  4 12:40:01 nas kernel: [ 7675.179243]          res 40/00:08:00:c7:60/00:00:98:01:00/40 Emask 0x10 (ATA bus error)
Jul  4 12:40:01 nas kernel: [ 7675.179302] ata3.00: status: { DRDY }
Jul  4 12:40:01 nas kernel: [ 7675.179320] ata3: hard resetting link
Jul  4 12:40:01 nas CRON[163593]: (root) CMD (/var/lib/openmediavault/cron.d/userdefined-2728f1c2-5920-447c-aef4-9f6f2928a97e >/dev/null 2>&1)
Jul  4 12:40:11 nas kernel: [ 7685.157633] ata2: softreset failed (1st FIS failed)
Jul  4 12:40:11 nas kernel: [ 7685.157726] ata2: hard resetting link
Jul  4 12:40:11 nas kernel: [ 7685.179592] ata3: softreset failed (1st FIS failed)
Jul  4 12:40:11 nas kernel: [ 7685.179677] ata3: hard resetting link
Jul  4 12:40:18 nas kernel: [ 7692.755236] ata3: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
Jul  4 12:40:18 nas kernel: [ 7692.864318] ata3.00: configured for UDMA/133
Jul  4 12:40:18 nas kernel: [ 7692.864335] ata3: EH complete
Jul  4 12:40:21 nas kernel: [ 7695.157700] ata2: softreset failed (1st FIS failed)
Jul  4 12:40:21 nas kernel: [ 7695.157793] ata2: hard resetting link
Jul  4 12:40:21 nas kernel: [ 7696.043224] ata2: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
Jul  4 12:40:22 nas kernel: [ 7696.117050] ata2.00: configured for UDMA/133
Jul  4 12:40:22 nas kernel: [ 7696.117079] ata2: EH complete
Jul  4 12:40:52 nas kernel: [ 7726.627420] ata3.00: exception Emask 0x0 SAct 0x800000 SErr 0x0 action 0x6 frozen
Jul  4 12:40:52 nas kernel: [ 7726.627551] ata3.00: failed command: READ FPDMA QUEUED
Jul  4 12:40:52 nas kernel: [ 7726.627631] ata3.00: cmd 60/20:b8:e0:59:37/00:00:21:04:00/40 tag 23 ncq dma 16384 in
Jul  4 12:40:52 nas kernel: [ 7726.627631]          res 40/00:01:00:01:00/00:00:00:00:00/00 Emask 0x4 (timeout)
Jul  4 12:40:52 nas kernel: [ 7726.627822] ata3.00: status: { DRDY }
Jul  4 12:40:52 nas kernel: [ 7726.627878] ata3: hard resetting link
Jul  4 12:40:53 nas kernel: [ 7727.103369] ata3: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
Jul  4 12:40:53 nas kernel: [ 7727.179532] ata3.00: configured for UDMA/133
Jul  4 12:40:53 nas kernel: [ 7727.179547] ata3: EH complete
...
Jul  4 12:51:34 nas kernel: [ 8368.110114] ata2.00: exception Emask 0x50 SAct 0x6000000 SErr 0x40d0802 action 0xe frozen
Jul  4 12:51:34 nas kernel: [ 8368.110220] ata2.00: irq_stat 0x00400040, connection status changed
Jul  4 12:51:34 nas kernel: [ 8368.110290] ata2: SError: { RecovComm HostInt PHYRdyChg CommWake 10B8B DevExch }
Jul  4 12:51:34 nas kernel: [ 8368.110370] ata2.00: failed command: READ FPDMA QUEUED
Jul  4 12:51:34 nas kernel: [ 8368.110434] ata2.00: cmd 60/00:c8:00:2f:e1/0a:00:93:01:00/40 tag 25 ncq dma 1310720 in
Jul  4 12:51:34 nas kernel: [ 8368.110434]          res 40/00:d0:00:39:e1/00:00:93:01:00/40 Emask 0x50 (ATA bus error)
Jul  4 12:51:34 nas kernel: [ 8368.110593] ata2.00: status: { DRDY }
Jul  4 12:51:34 nas kernel: [ 8368.110635] ata2.00: failed command: READ FPDMA QUEUED
Jul  4 12:51:34 nas kernel: [ 8368.110697] ata2.00: cmd 60/80:d0:00:39:e1/00:00:93:01:00/40 tag 26 ncq dma 65536 in
Jul  4 12:51:34 nas kernel: [ 8368.110697]          res 40/00:d0:00:39:e1/00:00:93:01:00/40 Emask 0x50 (ATA bus error)
Jul  4 12:51:34 nas kernel: [ 8368.110854] ata2.00: status: { DRDY }
Jul  4 12:51:34 nas kernel: [ 8368.110900] ata2: hard resetting link
Jul  4 12:51:44 nas kernel: [ 8378.113241] ata2: softreset failed (1st FIS failed)
Jul  4 12:51:44 nas kernel: [ 8378.113336] ata2: hard resetting link
Jul  4 12:51:54 nas kernel: [ 8388.112832] ata2: softreset failed (1st FIS failed)
Jul  4 12:51:54 nas kernel: [ 8388.112927] ata2: hard resetting link
Jul  4 12:51:54 nas kernel: [ 8389.010198] ata2: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
Jul  4 12:51:55 nas kernel: [ 8389.087286] ata2.00: configured for UDMA/133
Jul  4 12:51:55 nas kernel: [ 8389.087339] sd 1:0:0:0: [sdb] tag#25 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE cmd_age=21s
Jul  4 12:51:55 nas kernel: [ 8389.087346] sd 1:0:0:0: [sdb] tag#25 Sense Key : Illegal Request [current] 
Jul  4 12:51:55 nas kernel: [ 8389.087352] sd 1:0:0:0: [sdb] tag#25 Add. Sense: Unaligned write command
Jul  4 12:51:55 nas kernel: [ 8389.087359] sd 1:0:0:0: [sdb] tag#25 CDB: Read(16) 88 00 00 00 00 01 93 e1 2f 00 00 00 0a 00 00 00
Jul  4 12:51:55 nas kernel: [ 8389.087367] blk_update_request: I/O error, dev sdb, sector 6775975680 op 0x0:(READ) flags 0x84700 phys_seg 51 prio class 0
Jul  4 12:51:55 nas kernel: [ 8389.087558] sd 1:0:0:0: [sdb] tag#26 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE cmd_age=21s
Jul  4 12:51:55 nas kernel: [ 8389.087563] sd 1:0:0:0: [sdb] tag#26 Sense Key : Illegal Request [current] 
Jul  4 12:51:55 nas kernel: [ 8389.087568] sd 1:0:0:0: [sdb] tag#26 Add. Sense: Unaligned write command
Jul  4 12:51:55 nas kernel: [ 8389.087573] sd 1:0:0:0: [sdb] tag#26 CDB: Read(16) 88 00 00 00 00 01 93 e1 39 00 00 00 00 80 00 00
Jul  4 12:51:55 nas kernel: [ 8389.087579] blk_update_request: I/O error, dev sdb, sector 6775978240 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 0
Jul  4 12:51:55 nas kernel: [ 8389.087726] ata2: EH complete
...
Jul  4 13:20:02 nas kernel: [10076.153205] ata2.00: exception Emask 0x50 SAct 0x388000 SErr 0x48d0802 action 0xe frozen
Jul  4 13:20:02 nas kernel: [10076.153253] ata2.00: irq_stat 0x04400040, connection status changed
Jul  4 13:20:02 nas kernel: [10076.153279] ata2: SError: { RecovComm HostInt PHYRdyChg CommWake 10B8B LinkSeq DevExch }
Jul  4 13:20:02 nas kernel: [10076.153312] ata2.00: failed command: WRITE FPDMA QUEUED
Jul  4 13:20:02 nas kernel: [10076.153337] ata2.00: cmd 61/80:78:80:44:40/01:00:01:00:00/40 tag 15 ncq dma 196608 out
Jul  4 13:20:02 nas kernel: [10076.153337]          res 50/00:00:00:00:00/00:00:00:00:00/a0 Emask 0x50 (ATA bus error)
Jul  4 13:20:02 nas kernel: [10076.153397] ata2.00: status: { DRDY }
Jul  4 13:20:02 nas kernel: [10076.153413] ata2.00: failed command: WRITE FPDMA QUEUED
Jul  4 13:20:02 nas kernel: [10076.153437] ata2.00: cmd 61/88:98:f8:6b:37/00:00:00:00:00/40 tag 19 ncq dma 69632 out
Jul  4 13:20:02 nas kernel: [10076.153437]          res 50/00:00:00:00:00/00:00:00:00:00/a0 Emask 0x50 (ATA bus error)
Jul  4 13:20:02 nas kernel: [10076.153496] ata2.00: status: { DRDY }
Jul  4 13:20:02 nas kernel: [10076.153512] ata2.00: failed command: WRITE FPDMA QUEUED
Jul  4 13:20:02 nas kernel: [10076.153535] ata2.00: cmd 61/78:a0:80:6c:37/00:00:00:00:00/40 tag 20 ncq dma 61440 out
Jul  4 13:20:02 nas kernel: [10076.153535]          res 50/00:00:00:00:00/00:00:00:00:00/a0 Emask 0x50 (ATA bus error)
Jul  4 13:20:02 nas kernel: [10076.153594] ata2.00: status: { DRDY }
Jul  4 13:20:02 nas kernel: [10076.153610] ata2.00: failed command: WRITE FPDMA QUEUED
Jul  4 13:20:02 nas kernel: [10076.153634] ata2.00: cmd 61/80:a8:00:46:40/00:00:01:00:00/40 tag 21 ncq dma 65536 out
Jul  4 13:20:02 nas kernel: [10076.153634]          res 50/00:00:00:00:00/00:00:00:00:00/a0 Emask 0x50 (ATA bus error)
Jul  4 13:20:02 nas kernel: [10076.153692] ata2.00: status: { DRDY }
Jul  4 13:20:02 nas kernel: [10076.153710] ata2: hard resetting link
Jul  4 13:20:12 nas kernel: [10086.156400] ata2: softreset failed (1st FIS failed)
Jul  4 13:20:12 nas kernel: [10086.156496] ata2: hard resetting link
Jul  4 13:20:22 nas kernel: [10096.156464] ata2: softreset failed (1st FIS failed)
Jul  4 13:20:22 nas kernel: [10096.156559] ata2: hard resetting link
Jul  4 13:20:22 nas kernel: [10097.037333] ata2: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
Jul  4 13:20:23 nas kernel: [10097.124639] ata2.00: configured for UDMA/133
Jul  4 13:20:23 nas kernel: [10097.124680] ata2: EH complete

Display More

HannesJo · Jul 4th 2023

SMART status is green but in both of my data drives the Extended information tab shows at the end

Code

SATA Phy Event Counters (GP Log 0x11)
ID      Size     Value  Description
0x000a  2            2  Device-to-host register FISes sent due to a COMRESET
0x0001  2            0  Command failed due to ICRC error
0x0003  2            0  R_ERR response for device-to-host data FIS
0x0004  2            0  R_ERR response for host-to-device data FIS
0x0006  2            0  R_ERR response for device-to-host non-data FIS
0x0007  2            0  R_ERR response for host-to-device non-data FIS

Also in both drives SMART temperature logging sometimes show a ? since yesterday

Code

  58    2023-07-03 16:52    50  *******************************
  59    2023-07-03 17:51    49  ******************************
 ...    ..(  4 skipped).    ..  ******************************
  64    2023-07-03 22:46    49  ******************************
  65    2023-07-03 23:45     ?  -
  66    2023-07-04 00:44    48  *****************************
  67    2023-07-04 01:43     ?  -
  68    2023-07-04 02:42    48  *****************************
  69    2023-07-04 03:41     ?  -
  70    2023-07-04 04:40    45  **************************
  71    2023-07-04 05:39     ?  -
  72    2023-07-04 06:38    44  *************************
  73    2023-07-04 07:37     ?  -
  74    2023-07-04 08:36    44  *************************
  75    2023-07-04 09:35    38  *******************
  76    2023-07-04 10:34    38  *******************
  77    2023-07-04 11:33     ?  -
  78    2023-07-04 12:32    37  ******************
  79    2023-07-04 13:31    36  *****************

Display More

votdev · Jul 4th 2023

I would check the cables (unplug and re-plug them). If it does not help i would assume the disk is dying.

HannesJo · Jul 4th 2023

I just also checked the SSD and Extended info also shows that stuff. So 3 out of 3 drives. Looks like controller is dying or sth like that doesn't it?

Code

SATA Phy Event Counters (GP Log 0x11)
ID      Size     Value  Description
0x0001  2            0  Command failed due to ICRC error
0x0002  2            0  R_ERR response for data FIS
0x0003  2            0  R_ERR response for device-to-host data FIS
0x0004  2            0  R_ERR response for host-to-device data FIS
0x0005  2            0  R_ERR response for non-data FIS
0x0006  2            0  R_ERR response for device-to-host non-data FIS
0x0007  2            0  R_ERR response for host-to-device non-data FIS
0x0008  2            0  Device-to-host non-data FIS retries
0x0009  2            0  Transition from drive PhyRdy to drive PhyNRdy
0x000a  2            4  Device-to-host register FISes sent due to a COMRESET
0x000b  2            0  CRC errors within host-to-device FIS
0x000d  2            0  Non-CRC errors within host-to-device FIS
0x000f  2            0  R_ERR response for host-to-device data FIS, CRC
0x0010  2            0  R_ERR response for host-to-device data FIS, non-CRC
0x0012  2            0  R_ERR response for host-to-device non-data FIS, CRC
0x0013  2            0  R_ERR response for host-to-device non-data FIS, non-CRC

Display More

System crashed - ATA errors

Participate now!

Tags