March 30, 201412 yr The first time around the errors started several hours into a nocorrect check. The second time was just a matter of minutes. I cancelled the checks because I was too worried something would start corrupting data if it hadn't already. Mar 29 20:38:26 Tower kernel: mdcmd (45): check NOCORRECT Mar 29 20:38:26 Tower kernel: Mar 29 20:38:26 Tower kernel: md: recovery thread woken up ... Mar 29 20:38:26 Tower kernel: md: recovery thread checking parity... Mar 29 20:38:26 Tower kernel: md: using 4096k window, over a total of 3907018532 blocks. Mar 30 01:08:26 Tower kernel: sd 6:0:3:0: [sdj] command f7482a80 timed out Mar 30 01:08:26 Tower kernel: sas: Enter sas_scsi_recover_host busy: 1 failed: 1 Mar 30 01:08:26 Tower kernel: sas: trying to find task 0xf7501a00 Mar 30 01:08:26 Tower kernel: sas: sas_scsi_find_task: aborting task 0xf7501a00 Mar 30 01:08:26 Tower kernel: sas: sas_scsi_find_task: task 0xf7501a00 is aborted Mar 30 01:08:26 Tower kernel: sas: sas_eh_handle_sas_errors: task 0xf7501a00 is aborted Mar 30 01:08:26 Tower kernel: sas: ata9: end_device-6:3: cmd error handler Mar 30 01:08:26 Tower kernel: sas: ata6: end_device-6:0: dev error handler Mar 30 01:08:26 Tower kernel: sas: ata7: end_device-6:1: dev error handler Mar 30 01:08:26 Tower kernel: sas: ata8: end_device-6:2: dev error handler Mar 30 01:08:26 Tower kernel: sas: ata9: end_device-6:3: dev error handler Mar 30 01:08:26 Tower kernel: ata9.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x6 frozen Mar 30 01:08:26 Tower kernel: ata9.00: failed command: READ FPDMA QUEUED Mar 30 01:08:26 Tower kernel: ata9.00: cmd 60/00:00:98:ef:2c/04:00:97:00:00/40 tag 0 ncq 524288 in Mar 30 01:08:26 Tower kernel: res 40/00:0c:78:4a:23/00:00:97:00:00/40 Emask 0x4 (timeout) Mar 30 01:08:26 Tower kernel: ata9.00: status: { DRDY } Mar 30 01:08:26 Tower kernel: ata9: hard resetting link Mar 30 01:08:26 Tower kernel: sas: sas_form_port: phy3 belongs to port3 already(1)! Mar 30 01:08:28 Tower kernel: drivers/scsi/mvsas/mv_sas.c 1527:mvs_I_T_nexus_reset for device[3]:rc= 0 Mar 30 01:08:28 Tower kernel: ata9.00: configured for UDMA/133 Mar 30 01:08:28 Tower kernel: ata9: EH complete Mar 30 01:08:28 Tower kernel: sas: --- Exit sas_scsi_recover_host: busy: 0 failed: 0 tries: 1 Mar 30 01:10:35 Tower kernel: mdcmd (46): nocheck Mar 30 01:10:35 Tower kernel: md: md_do_sync: got signal, exit... Mar 30 01:10:35 Tower kernel: md: recovery thread sync completion status: -4 Mar 30 01:39:18 Tower kernel: NTFS driver 2.1.30 [Flags: R/W MODULE]. Mar 30 01:39:21 Tower kernel: mdcmd (47): check NOCORRECT Mar 30 01:39:21 Tower kernel: Mar 30 01:39:21 Tower kernel: md: recovery thread woken up ... Mar 30 01:39:21 Tower kernel: md: recovery thread checking parity... Mar 30 01:39:21 Tower kernel: md: using 4096k window, over a total of 3907018532 blocks. Mar 30 01:46:30 Tower kernel: sd 6:0:2:0: [sdi] command f3d47540 timed out Mar 30 01:46:30 Tower kernel: sas: Enter sas_scsi_recover_host busy: 1 failed: 1 Mar 30 01:46:30 Tower kernel: sas: trying to find task 0xefd6e300 Mar 30 01:46:30 Tower kernel: sas: sas_scsi_find_task: aborting task 0xefd6e300 Mar 30 01:46:30 Tower kernel: sas: sas_scsi_find_task: task 0xefd6e300 is aborted Mar 30 01:46:30 Tower kernel: sas: sas_eh_handle_sas_errors: task 0xefd6e300 is aborted Mar 30 01:46:30 Tower kernel: sas: ata8: end_device-6:2: cmd error handler Mar 30 01:46:30 Tower kernel: sas: ata6: end_device-6:0: dev error handler Mar 30 01:46:30 Tower kernel: sas: ata7: end_device-6:1: dev error handler Mar 30 01:46:30 Tower kernel: sas: ata8: end_device-6:2: dev error handler Mar 30 01:46:30 Tower kernel: ata8.00: exception Emask 0x0 SAct 0x10 SErr 0x0 action 0x6 frozen Mar 30 01:46:30 Tower kernel: ata8.00: failed command: READ FPDMA QUEUED Mar 30 01:46:30 Tower kernel: ata8.00: cmd 60/00:00:00:9f:c6/04:00:03:00:00/40 tag 4 ncq 524288 in Mar 30 01:46:30 Tower kernel: res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) Mar 30 01:46:30 Tower kernel: ata8.00: status: { DRDY } Mar 30 01:46:30 Tower kernel: ata8: hard resetting link Mar 30 01:46:30 Tower kernel: sas: ata9: end_device-6:3: dev error handler Mar 30 01:46:30 Tower kernel: sas: sas_form_port: phy2 belongs to port2 already(1)! Mar 30 01:46:32 Tower kernel: drivers/scsi/mvsas/mv_sas.c 1527:mvs_I_T_nexus_reset for device[2]:rc= 0 Mar 30 01:46:32 Tower kernel: ata8.00: configured for UDMA/133 Mar 30 01:46:32 Tower kernel: ata8.00: device reported invalid CHS sector 0 Mar 30 01:46:32 Tower kernel: ata8: EH complete Mar 30 01:46:32 Tower kernel: sas: --- Exit sas_scsi_recover_host: busy: 0 failed: 0 tries: 1 Mar 30 01:58:38 Tower kernel: mdcmd (48): nocheck Mar 30 01:58:38 Tower kernel: md: md_do_sync: got signal, exit... Mar 30 01:58:38 Tower kernel: md: recovery thread sync completion status: -4 sdj and sdi are both on my newly installed sas2lp-mv8. And yes I had to reflash it to get it working in the first place. Int13 is disabled. One odd thing I noticed in the setup menu is under "RAID mode" it says "N/A" instead of "JBOD" like the old saslp-mv8 which is still installed, if that matters. Probably unrelated: One thing in the full syslog I've always wondered about is this line Mar 29 20:33:48 Tower kernel: AMD_IDE: probe of 0000:00:06.0 failed with error -12 But that's been happening for years since I started with 4.x (only moved to 5.0.5 a couple weeks ago). Any advice? Need more info? Am I being paranoid? No errors in parity were detected as far as it got, and the check did continue past the error on its own. Maybe I should have let it finish. Just hate to see red in unmenu. syslog-2014-03-30.txt
March 31, 201412 yr Author So I swapped the drives on the motherboard with the drives on the sas2, ran another check, and the error came up again on one of the drives on the sas2. Mar 30 12:56:00 Tower kernel: mdcmd (45): check NOCORRECT Mar 30 12:56:00 Tower kernel: Mar 30 12:56:00 Tower kernel: md: recovery thread woken up ... Mar 30 12:56:00 Tower kernel: md: recovery thread checking parity... Mar 30 12:56:00 Tower kernel: md: using 4096k window, over a total of 3907018532 blocks. Mar 30 16:15:47 Tower kernel: sd 6:0:0:0: [sdg] command f3de86c0 timed out Mar 30 16:15:47 Tower kernel: sas: Enter sas_scsi_recover_host busy: 1 failed: 1 Mar 30 16:15:47 Tower kernel: sas: trying to find task 0xf7705400 Mar 30 16:15:47 Tower kernel: sas: sas_scsi_find_task: aborting task 0xf7705400 Mar 30 16:15:47 Tower kernel: sas: sas_scsi_find_task: task 0xf7705400 is aborted Mar 30 16:15:47 Tower kernel: sas: sas_eh_handle_sas_errors: task 0xf7705400 is aborted Mar 30 16:15:47 Tower kernel: sas: ata6: end_device-6:0: cmd error handler Mar 30 16:15:47 Tower kernel: sas: ata6: end_device-6:0: dev error handler Mar 30 16:15:47 Tower kernel: ata6.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen Mar 30 16:15:47 Tower kernel: ata6.00: failed command: READ DMA EXT Mar 30 16:15:47 Tower kernel: ata6.00: cmd 25/00:00:08:79:db/00:04:6f:00:00/e0 tag 0 dma 524288 in Mar 30 16:15:47 Tower kernel: res 40/00:00:17:a4:b4/00:00:6f:00:00/e0 Emask 0x4 (timeout) Mar 30 16:15:47 Tower kernel: ata6.00: status: { DRDY } Mar 30 16:15:47 Tower kernel: ata6: hard resetting link Mar 30 16:15:47 Tower kernel: sas: ata7: end_device-6:1: dev error handler Mar 30 16:15:47 Tower kernel: sas: ata8: end_device-6:2: dev error handler Mar 30 16:15:47 Tower kernel: sas: ata9: end_device-6:3: dev error handler Mar 30 16:15:47 Tower kernel: sas: sas_form_port: phy0 belongs to port0 already(1)! Mar 30 16:15:49 Tower kernel: drivers/scsi/mvsas/mv_sas.c 1527:mvs_I_T_nexus_reset for device[0]:rc= 0 Mar 30 16:15:50 Tower kernel: ata6.00: configured for UDMA/133 Mar 30 16:15:50 Tower kernel: ata6: EH complete Mar 30 16:15:50 Tower kernel: sas: --- Exit sas_scsi_recover_host: busy: 0 failed: 0 tries: 1 Mar 31 00:47:13 Tower kernel: md: sync done. time=42672sec Mar 31 00:47:13 Tower kernel: md: recovery thread sync completion status: 0 So that's a total of 3 different drives that have had this error, only while attached to the sas2. But the parity check had no errors, so I guess I won't worry too much. Though if someone could walk me through what's happening in the log there, I'd appreciate it. Thanks!
March 31, 201412 yr Possibly it is a bad / marginal SATA cable. Or maybe a bad power splitter / connector. That would be my initial thoughts.
April 2, 201412 yr In all 3 cases, it is a read request that took too long, call it a slow read. They all were harmless, as there were no further issues after a reset and retry, so it appears like something you may have to live with for awhile, with that SAS card. Perhaps in the future there will be a firmware update for the card that will improve that, or there will be a newer version of the mvsas driver that has been patched to better handle slow reads. I wouldn't be surprised if there isn't a patch already out there that increases the timeout, that just tells it to wait a bit longer before reporting a problem. I have no ideas why these particular reads were so slow, could be a number of things.
Archived
This topic is now archived and is closed to further replies.