Spinanie rozpiętej macierzy

Właśnie miałem okazję przećwiczyć scenariusz awarii dysku należącego do prostej macierzy RAID. A przy okazji, ponieważ problem dotyczył drivera, a nie samego dysku, czekało mnie spinanie macierzy z powrotem.

Alarm

Właśnie sobie spokojnie grałem w szachy, gdy zamigotał mi następujący email:

Od:  mdadm monitoring <root@pitagoras.mekk.waw.pl>
Do:  diskalarm@pitagoras.mekk.waw.pl

Temat:  Fail event on /dev/md1:pitagoras

This is an automatically generated mail message from mdadm 
running on pitagoras

A Fail event had been detected on md device /dev/md1.
It could be related to component device /dev/sdc3.
Faithfully yours, etc.

P.S. The /proc/mdstat file currently contains the following:

Personalities : [linear] [multipath] [raid0] [raid1] [raid6] [raid5] [raid4] [raid10]
md0 : active raid1 sdc1[0] sdb1[1]
      10482304 blocks [2/2] [UU]
md1 : active raid1 sdc3[2](F) sdb3[1]
      610445824 blocks [2/1] [_U]

Po chwili podobny, dotyczący /dev/md0 (mam konfigurację opisaną w tym artykule).

Przykrość związaną z przeczuwaną koniecznością kupienia nowego dysku skontrowało mi trochę zadowolenie że zdążyłem zrobić macierz. No – ale zacząłem od sprawdzenia, co się właściwie stało.

Diagnoza

smartctl -l error /dev/sdc o żadnych błędach nie poinformowało (ani od razu, ani po smartctl --test=short /dev/sdc), więc na bazie wcześniejszych doświadczeń zacząłem mieć pewne podejrzenia.

Przegląd logów pozwolił mi znaleźć w /var/log/messages następujące informacje (wybrałem tylko kluczowe, było tego sporo więcej):

Sep  6 21:54:24 platon kernel: [266664.967625] sd 4:0:0:0: [sdc] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
Sep  6 21:54:24 platon kernel: [266664.967629] sd 4:0:0:0: [sdc] Sense Key : Medium Error [current] [descriptor]
Sep  6 21:54:24 platon kernel: [266664.967633] Descriptor sense data with sense descriptors (in hex):
Sep  6 21:54:24 platon kernel: [266664.967636]         72 03 11 04 00 00 00 0c 00 0a 80 00 00 00 00 00
Sep  6 21:54:24 platon kernel: [266664.967641]         4a 85 2b cf
Sep  6 21:54:24 platon kernel: [266664.967644] sd 4:0:0:0: [sdc] Add. Sense: Unrecovered read error - auto reallocate failed
Sep  6 21:54:24 platon kernel: [266664.967649] end_request: I/O error, dev sdc, sector 1250241487
Sep  6 21:54:24 platon kernel: [266664.967661] ata5: EH complete
Sep  6 21:54:24 platon kernel: [266664.530191] sd 4:0:0:0: [sdc] 1250263728 512-byte hardware sectors (640135 MB)
Sep  6 21:54:24 platon kernel: [266664.533782] sd 4:0:0:0: [sdc] Write Protect is off
Sep  6 21:54:24 platon kernel: [266664.533954] sd 4:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Sep  6 21:54:24 platon kernel: [266664.994912] sd 4:0:0:0: [sdc] 1250263728 512-byte hardware sectors (640135 MB)
Sep  6 21:54:24 platon kernel: [266679.971455]          res 40/00:00:cf:2b:85/40:00:4a:00:00/e0 Emask 0x4 (timeout)
Sep  6 21:54:24 platon kernel: [266682.644352] ata5: port is slow to respond, please be patient (Status 0xd0)
Sep  6 21:54:24 platon kernel: [266684.512724] ata5: device not ready (errno=-16), forcing hardreset
Sep  6 21:54:24 platon kernel: [266684.512732] ata5: hard resetting link
Sep  6 21:54:24 platon kernel: [266684.750413] ata5: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Sep  6 21:54:24 platon kernel: [266685.245969] ata5.00: failed to IDENTIFY (I/O error, err_mask=0x3)
Sep  6 21:54:24 platon kernel: [266685.245980] ata5: failed to recover some devices, retrying in 5 secs
Sep  6 21:54:24 platon kernel: [266687.743549] ata5: hard resetting link
Sep  6 21:54:24 platon kernel: [266687.980755] ata5: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Sep  6 21:54:24 platon kernel: [266687.568303] ata5.00: failed to IDENTIFY (I/O error, err_mask=0x3)
Sep  6 21:54:24 platon kernel: [266687.568315] ata5: failed to recover some devices, retrying in 5 secs
Sep  6 21:54:24 platon kernel: [266690.065314] ata5: hard resetting link
Sep  6 21:54:24 platon kernel: [266690.304988] ata5: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Sep  6 21:54:24 platon kernel: [266690.800569] ata5.00: failed to IDENTIFY (I/O error, err_mask=0x3)
Sep  6 21:54:24 platon kernel: [266690.800578] ata5.00: disabled
Sep  6 21:54:24 platon kernel: [266691.206909] ata5: soft resetting link
Sep  6 21:54:24 platon kernel: [266691.284344] ata5: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Sep  6 21:54:24 platon kernel: [266691.284368] ata5: EH complete
Sep  6 21:54:24 platon kernel: [266691.284387] sd 4:0:0:0: [sdc] Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK,SUGGEST_OK
Sep  6 21:54:24 platon kernel: [266691.284391] end_request: I/O error, dev sdc, sector 1250241379
Sep  6 21:54:24 platon kernel: [266691.284398] ^IOperation continuing on 1 devices
Sep  6 21:54:24 platon kernel: [266691.284888] sd 4:0:0:0: [sdc] Write Protect is off
Sep  6 21:54:24 platon kernel: [266691.338223] RAID1 conf printout:
Sep  6 21:54:24 platon kernel: [266691.338230]  --- wd:1 rd:2
Sep  6 21:54:24 platon kernel: [266691.338233]  disk 0, wo:1, o:0, dev:sdc3
Sep  6 21:54:24 platon kernel: [266691.338235]  disk 1, wo:0, o:1, dev:sdb3
Sep  6 21:54:24 platon kernel: [266691.342727] RAID1 conf printout:
Sep  6 21:54:24 platon kernel: [266691.342731]  --- wd:1 rd:2
Sep  6 21:54:24 platon kernel: [266691.342733]  disk 1, wo:0, o:1, dev:sdb3

Komunikat port is slow to respond to dobrze mi już znany problem z dyskami SATA w towarzystwie CD/DVD. Dobra, najprawodpodobniej dysk jest OK ale znowu mam kłopot na styku firmware i driverów. Pogooglowałem trochę za nowszymi informacjami i oprócz zaciekłych dyskusji, kto winny (firmware DVD doszło do listy) znalazłem sugestię dołożenia do parametrów uruchamiania jądra zapisu combined_mode=libata (sugestię przestawienia trybu dysków w BIOSie już znałem, ale mój BIOS niestety tej opcji nie posiada). Dołożyłem parametr (w /boot/grub/menu.lst) – metodą Ubuntu, czyli edytując wiersz # kopt do postaci:

# kopt=root=UUID=bc6085fc-aaad-4c7b-bac8-2f00b6e5156e ro combined_mode=libata

a następnie uruchamiając update-grub i restartując komputer. Na razie chyba pomogło, choć rekompilacja jądra bez libata kusi coraz bardziej (rekompilować o tyle nie mam ochoty, że potem trzeba to powtarzać przy każdej aktualizacji do nowego jądra, nudna i niepotrzebna praca).

Dorzucę jeszcze, że po restarcie przyszedł mail przypominający, że pracuję przy użyciu zdegradowanej macierzy (DegradedArray event on /dev/md1:pitagoras)

Spinanie z powrotem

Kupowanie nowego dysku, wkładanie go zamiast starego i partycjonowanie mogłem sobie na szczęście odpuścić, zostało jednak do zrobienia powtórne spięcie macierzy. Czyli po prostu:

$ mdadm /dev/md0 --add /dev/sdc1
mdadm: re-added /dev/sdc1
$ mdadm /dev/md1 --add /dev/sdc3
mdadm: re-added /dev/sdc3

System przystąpił do resynchronizacji macierzy:

$ cat /proc/mdstat
Personalities : [linear] [multipath] [raid0] [raid1] [raid6] [raid5] [raid4] [raid10]
md0 : active raid1 sdc1[2] sdb1[1]
      10482304 blocks [2/1] [_U]
      [===>.................]  recovery = 15.9% (1668480/10482304) finish=1.4min speed=104280K/sec

md1 : active raid1 sdc3[2] sdb3[1]
      610445824 blocks [2/1] [_U]
       resync=DELAYED

i po paru godzinach macierz była ponownie w normalnym stanie.