Hard reset SATA Link während Data Scrubbing

[primesyn]

Hallo zusammen,

ich habe hier im Forum schon einen Thread laufen, bei dem ich zum Thema Fehlerbehebung beim Data Scrubbing viele Fragen habe. Meine Platten haben Bad Sectors.

Während des letzten Scrubbings, ziemlich am Ende, hatte der SATA link auf einmal permanent hard resets. Die Frage ist, ob das daran liegt, weil die Platten gerade einen bad sector versuchen zu lesen oder das SATA Interface Mainbord- oder Plattenseitig ein Problem hat?

Ich habe eine DS 411+ mit 4x WD20EARS. Diese Platten aus der Caviar green Serie machen keine TLER. Kann es deswegen sein, dass die Platten solange nicht antworten und der Treiber/Kernel dann knallhart einfach den Bus resettet? Müssten dann Timeoutwerte erhöht werden? Oder doch das Interface ein Problem?

Unten das Log des Kernels. Dabei fällt auf das der ATA Treiber plötzlich haufenweise timeouts bringt und abschließend das Interface resettet. Die Prozedur wiederholt sich etliche Male. Dazwischen wird erst NCQ abgeschaltet, dann auf 1,5 GBit runter, dann nur noch PIO4 Speed. Am Schluss korrigiert der MD dann noch haufenweise Sektoren an einem Stück. Mich wundert, dass das in einem Block passiert und nicht schon zwischendrin (zwischen den Resets).

Ist das Verhalten normal?

Danke
Christian

[140396.414771] md: requested-resync of RAID array md2
[140396.419672] md: minimum _guaranteed_  speed: 10000 KB/sec/disk.
[140396.425756] md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for requested-resync.
[140396.436115] md: using 128k window, over a total of 1948780672k.
[177113.824089] ata3.00: exception Emask 0x0 SAct 0x7fffffff SErr 0x0 action 0x6 frozen
[177113.831844] ata3.00: failed command: READ FPDMA QUEUED
[177113.837099] ata3.00: cmd 60/08:00:38:35:34/00:00:e3:00:00/40 tag 0 ncq 4096 in
[177113.837103]          res 40/00:ff:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[177113.851897] ata3.00: status: { DRDY }
...
[177114.548305] ata3.00: failed command: READ FPDMA QUEUED
[177114.553546] ata3.00: cmd 60/08:f0:10:36:34/00:00:e3:00:00/40 tag 30 ncq 4096 in
[177114.553550]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[177114.568427] ata3.00: status: { DRDY }
[177114.572197] ata3: hard resetting link
[177114.880030] ata3: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[177114.934574] ata3.00: configured for UDMA/133
[177114.938957] ata3.00: device reported invalid CHS sector 0
[177115.109551] ata3: EH complete
[177175.776070] ata3.00: exception Emask 0x0 SAct 0x67800000 SErr 0x0 action 0x6 frozen
[177175.783828] ata3.00: failed command: READ FPDMA QUEUED
[177175.789075] ata3.00: cmd 60/08:b8:58:35:34/00:00:e3:00:00/40 tag 23 ncq 4096 in
[177175.789079]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[177175.803955] ata3.00: status: { DRDY }
...
[177175.903433] ata3.00: failed command: READ FPDMA QUEUED
[177175.908678] ata3.00: cmd 60/08:f0:38:35:34/00:00:e3:00:00/40 tag 30 ncq 4096 in
[177175.908681]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[177175.923548] ata3.00: status: { DRDY }
[177175.927314] ata3: hard resetting link
[177176.236033] ata3: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[177176.251773] ata3.00: configured for UDMA/133
[177176.283594] ata3.00: device reported invalid CHS sector 0
[177176.289095] ata3: EH complete
[177236.704081] ata3.00: exception Emask 0x0 SAct 0x3f SErr 0x0 action 0x6 frozen
[177236.711322] ata3.00: failed command: READ FPDMA QUEUED
[177236.716560] ata3.00: cmd 60/08:00:38:35:34/00:00:e3:00:00/40 tag 0 ncq 4096 in
[177236.716563]          res 40/00:ff:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[177236.731345] ata3.00: status: { DRDY }
[177236.735098] ata3.00: failed command: READ FPDMA QUEUED
[177236.740332] ata3.00: cmd 60/08:08:40:35:34/00:00:e3:00:00/40 tag 1 ncq 4096 in
[177236.740335]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[177236.755118] ata3.00: status: { DRDY }
...
[177236.854208] ata3: hard resetting link
[177237.162031] ata3: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[177237.178193] ata3.00: configured for UDMA/133
[177237.210027] ata3.00: device reported invalid CHS sector 0
[177237.215535] ata3: EH complete
[177297.888051] ata3.00: NCQ disabled due to excessive errors
[177297.893548] ata3.00: exception Emask 0x0 SAct 0x3f SErr 0x0 action 0x6 frozen
[177297.900773] ata3.00: failed command: READ FPDMA QUEUED
[177297.906013] ata3.00: cmd 60/08:00:58:35:34/00:00:e3:00:00/40 tag 0 ncq 4096 in
[177297.906016]          res 40/00:ff:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[177297.920798] ata3.00: status: { DRDY }
...
[177298.019849] ata3.00: failed command: READ FPDMA QUEUED
[177298.025083] ata3.00: cmd 60/08:28:38:35:34/00:00:e3:00:00/40 tag 5 ncq 4096 in
[177298.025086]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[177298.039868] ata3.00: status: { DRDY }
[178273.790715] ata3: hard resetting link
[178274.099028] ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[178274.114112] ata3.00: configured for UDMA/33
[178274.118397] ata3.00: device reported invalid CHS sector 0
[178274.123906] ata3: EH complete
[178334.816070] ata3.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[178334.823215] ata3.00: failed command: READ DMA EXT
[178334.828018] ata3.00: cmd 25/00:b8:80:31:34/00:03:e3:00:00/e0 tag 0 dma 487424 in
[178334.828022]          res 40/00:ff:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[178334.842978] ata3.00: status: { DRDY }
[178334.846735] ata3: hard resetting link
[178335.155033] ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[178335.169748] ata3.00: configured for UDMA/33
[178335.174033] ata3.00: device reported invalid CHS sector 0
[178335.179573] sd 2:0:0:0: [sdc]  Result: hostbyte=0x00 driverbyte=0x08
[178335.186048] sd 2:0:0:0: [sdc]  Sense Key : 0xb [current] [descriptor]
[178335.192669] Descriptor sense data with sense descriptors (in hex):
[178335.198954]         72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00 
[178335.205729]         00 00 00 00 
[178335.209154] sd 2:0:0:0: [sdc]  ASC=0x0 ASCQ=0x0
[178335.213817] sd 2:0:0:0: [sdc] CDB: cdb[0]=0x28: 28 00 e3 34 31 80 00 03 b8 00
[178335.221307] end_request: I/O error, dev sdc, sector 3811848576
[178335.227478] ata3: EH complete
[178355.469378] read error corrected, md2, sdc5 index [2], sector 3811848584 [raid5_end_read_request]
[178355.470359] md/raid:md2: read error corrected (8 sectors at 3802395296 on sdc5)
[178355.470359] read error corrected, md2, sdc5 index [2], sector 3811848592 [raid5_end_read_request]
[178355.470359] md/raid:md2: read error corrected (8 sectors at 3802395304 on sdc5)
[178355.485779] read error corrected, md2, sdc5 index [2], sector 3811848600 [raid5_end_read_request]
[178355.485779] md/raid:md2: read error corrected (8 sectors at 3802395312 on sdc5)
[178355.502120] read error corrected, md2, sdc5 index [2], sector 3811848608 [raid5_end_read_request]
[178355.502120] md/raid:md2: read error corrected (8 sectors at 3802395320 on sdc5)
[178355.518478] read error corrected, md2, sdc5 index [2], sector 3811848616 [raid5_end_read_request]
[178355.518478] md/raid:md2: read error corrected (8 sectors at 3802395328 on sdc5)
[178355.534831] read error corrected, md2, sdc5 index [2], sector 3811848624 [raid5_end_read_request]
[178355.534831] md/raid:md2: read error corrected (8 sectors at 3802395336 on sdc5)
[178355.551185] read error corrected, md2, sdc5 index [2], sector 3811848632 [raid5_end_read_request]
[178355.551185] md/raid:md2: read error corrected (8 sectors at 3802395344 on sdc5)
[178355.567539] read error corrected, md2, sdc5 index [2], sector 3811848640 [raid5_end_read_request]
[178355.567539] md/raid:md2: read error corrected (8 sectors at 3802395352 on sdc5)
[178355.583894] read error corrected, md2, sdc5 index [2], sector 3811848648 [raid5_end_read_request]
[178355.583894] md/raid:md2: read error corrected (8 sectors at 3802395360 on sdc5)
[178355.600248] read error corrected, md2, sdc5 index [2], sector 3811848656 [raid5_end_read_request]
[178355.600248] md/raid:md2: read error corrected (8 sectors at 3802395368 on sdc5)
[178355.616602] read error corrected, md2, sdc5 index [2], sector 3811848664 [raid5_end_read_request]
[178355.633022] read error corrected, md2, sdc5 index [2], sector 3811848672 [raid5_end_read_request]
[178355.641921] read error corrected, md2, sdc5 index [2], sector 3811848680 [raid5_end_read_request]
[178355.650879] read error corrected, md2, sdc5 index [2], sector 3811848688 [raid5_end_read_request]
[178355.659840] read error corrected, md2, sdc5 index [2], sector 3811848696 [raid5_end_read_request]
...
[178356.574851] read error corrected, md2, sdc5 index [2], sector 3811849504 [raid5_end_read_request]
[178356.583820] read error corrected, md2, sdc5 index [2], sector 3811849512 [raid5_end_read_request]
[178356.592791] read error corrected, md2, sdc5 index [2], sector 3811849520 [raid5_end_read_request]
[178356.601763] read error corrected, md2, sdc5 index [2], sector 3811849528 [raid5_end_read_request]
[179737.327473] md: md2: requested-resync done.