06-02-2019, 07:50 AM
There are two kinds of SATA interfaces start: sequence and simultaneous.
Fist, sequence start case is in earlier log:
After both controller interfaces initialization at 2.82s, the first interface was successfully negotiated at full speed 6Gbps at 3.28s then the disk was attached at 3.42s. At 6.02s file system mounting of first interface HDD was completed without of errors.
Second interface behaved not as good as first. Only at 8.82s it start negotiation. At 13.37s a soft reset happened. At 18.90s 6Gbps link at SATA2 was established. But at 23.92s timeout error was triggered. It was negotiated to 6Gbps again at 34.46 but failed again at 34.48 with "polling device detection hint" error (device absent equivalent, IMHO). After two failures the speed was decreased to 3Gbps at 34.49s. Then file system mounting went OK and was finished for SATA 2 at 41.17s.
Because the drives was attached not simultaneously, with a delay of 40.112645-3.425786=36.68s, there were no chances for RAID to bring up.
IMHO, a severe hardware problem. What if you start the drives completely separate?
Try to record a logs for only one ATA1 interface connected (only one HDD connected) while changing the cable and the drive. Will be there a difference between the cables and between the drives?
The trial when both drivers were up and the RAID was detected is different. Can't analyze right now. It is better to collect additional information by making the test with cable/drive changing.
Also repeat the test with cable and drive change for ATA2 interface. Record a logs.
Probably these tests and logs will give more information.
Fist, sequence start case is in earlier log:
Code:
[ 2.822172] ata1: SATA max UDMA/133 abar m512@0xfa010000 port 0xfa010100 irq 239
[ 2.824016] ata2: SATA max UDMA/133 abar m512@0xfa010000 port 0xfa010180 irq 239
[ 3.289330] ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[ 3.295986] ata1.00: ATA-10: WDC WD40EFRX-68N32N0, 82.00A82, max UDMA/133
[ 3.307042] ata1.00: 7814037168 sectors, multi 16: LBA48 NCQ (depth 31/32), AA
[ 3.319425] ata1.00: configured for UDMA/133
[ 3.331341] scsi 0:0:0:0: Direct-Access ATA WDC WD40EFRX-68N 0A82 PQ: 0 ANSI: 5
[ 3.338871] sd 0:0:0:0: [sda] 7814037168 512-byte logical blocks: (4.00 TB/3.64 TiB)
[ 3.346751] sd 0:0:0:0: [sda] 4096-byte physical blocks
[ 3.354588] sd 0:0:0:0: [sda] Write Protect is off
[ 3.362123] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
[ 3.362305] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 3.418361] sda: sda1
[ 3.425786] sd 0:0:0:0: [sda] Attached SCSI disk
[ 5.102569] systemd[1]: Mounted FUSE Control File System.
[ 5.108546] systemd[1]: Mounted Configuration File System.
[ 5.116147] systemd[1]: Started Journal Service.
[ 5.179134] systemd-journald[317]: Received request to flush runtime journal from PID 1
[ 5.695722] ata1.00: configured for UDMA/133
[ 5.699739] ata1: EH complete
[ 5.704375] sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[ 6.004362] FAT-fs (mmcblk0p6): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive!
[ 6.029101] FAT-fs (mmcblk0p6): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[ 6.775230] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: user_xattr,usrjquota=aquota.user,grpjquota=aquota.group,jqfmt=vfsv0,acl
[ 8.824559] ata2: link is slow to respond, please be patient (ready=0)
[ 13.377369] ata2: softreset failed (device not ready)
[ 18.900596] ata2: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[ 23.914593] ata2.00: qc timeout (cmd 0xec)
[ 23.928554] ata2.00: failed to IDENTIFY (I/O error, err_mask=0x4)
[ 33.991567] ata2: softreset failed (device not ready)
[ 34.465590] ata2: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[ 34.480898] ata2.00: failed to IDENTIFY (I/O error, err_mask=0x100)
[ 34.495434] ata2: limiting SATA link speed to 3.0 Gbps
[ 39.939592] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[ 39.955188] ata2.00: ATA-10: WDC WD40EFRX-68N32N0, 82.00A82, max UDMA/133
[ 39.969728] ata2.00: 7814037168 sectors, multi 16: LBA48 NCQ (depth 31/32), AA
[ 39.981263] ata2.00: configured for UDMA/133
[ 39.992757] scsi 1:0:0:0: Direct-Access ATA WDC WD40EFRX-68N 0A82 PQ: 0 ANSI: 5
[ 40.002185] sd 1:0:0:0: [sdb] 7814037168 512-byte logical blocks: (4.00 TB/3.64 TiB)
[ 40.010183] sd 1:0:0:0: [sdb] 4096-byte physical blocks
[ 40.019003] sd 1:0:0:0: [sdb] Write Protect is off
[ 40.023064] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
[ 40.023151] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 40.093354] sdb: sdb1
[ 40.112645] sd 1:0:0:0: [sdb] Attached SCSI disk
[ 40.235716] ata2.00: configured for UDMA/133
[ 40.246159] ata2: EH complete
[ 40.262243] sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[ 41.178347] EXT4-fs (sdb1): mounted filesystem with ordered data mode. Opts: user_xattr,usrjquota=aquota.user,grpjquota=aquota.group,jqfmt=vfsv0,aclAfter both controller interfaces initialization at 2.82s, the first interface was successfully negotiated at full speed 6Gbps at 3.28s then the disk was attached at 3.42s. At 6.02s file system mounting of first interface HDD was completed without of errors.
Second interface behaved not as good as first. Only at 8.82s it start negotiation. At 13.37s a soft reset happened. At 18.90s 6Gbps link at SATA2 was established. But at 23.92s timeout error was triggered. It was negotiated to 6Gbps again at 34.46 but failed again at 34.48 with "polling device detection hint" error (device absent equivalent, IMHO). After two failures the speed was decreased to 3Gbps at 34.49s. Then file system mounting went OK and was finished for SATA 2 at 41.17s.
Because the drives was attached not simultaneously, with a delay of 40.112645-3.425786=36.68s, there were no chances for RAID to bring up.
IMHO, a severe hardware problem. What if you start the drives completely separate?
Try to record a logs for only one ATA1 interface connected (only one HDD connected) while changing the cable and the drive. Will be there a difference between the cables and between the drives?
The trial when both drivers were up and the RAID was detected is different. Can't analyze right now. It is better to collect additional information by making the test with cable/drive changing.
Also repeat the test with cable and drive change for ATA2 interface. Record a logs.
Probably these tests and logs will give more information.