Dotaz: CentOS 5.3, RAID1, neustálé SATA chyby DRDY ERR

[Spyboy]

Mám tu zakletý server:

Před cca rokem a půl jsem umístil do datacentra nový Supermicro server s 4x 500 GB WD disky. Server využívám pro OpenVZ virtualizaci na CentOS 5.3 (ovzkernel 2.6.18).

Přibližně po půl roce se začaly na jednom z disků objevovat media error chyby. Pro jistotu jsem vyměnil disk. Jenže po pár měsících "odešel" pro změnu druhý (stejné chyby). Takto došlo celkem k dvojnásobné výměně sda a sdb disků, které mám v RAID1 poli. Sdc a sdd mám pro zálohy a v RAIDu nejsou - s nimi problémy nemám.

Vždy se frekvence chyb zvyšovala, systém následně vyhodil jeden z disků z RAIDu a po chvíli ten zbylý hodil do read-only módu. Po výměně disku a resyncu RAIDu vše jelo zase třeba tři měsíce bez problému.

Situaci jsem řešil s Abacusem, dodavatelem serveru, kde po několikadenním testování nezjistili žádný problém. To samé s disky. Mezitím jsem si pronajal dedikovaný server (stejný typ a konfigurace) a zastrčil do něj disky z původního a vše opět jelo. Na čas. Po tomto jsem HW chybu vyloučil.

("Původní" server s "vadnými" disky mám nyní umístěný jinde a žádné problémy nejsou.)

V současnosti se doba od resyncu RAIDu po výskyt chyb a následné rozpadnutí RAIDu snížila na několik dní. Googluju, procházím diskuze, ale nenašel jsem nic, co bych nezkoušel, nebo bylo na první pohled úplně zcestné.

Zkoušel jsem upgrade kernelu (v rámci větve 2.6.18 - novější stable ovzkernelu není k dispozici), bootovat s acpi=off, acpi=noirq, noapic, vypínal jsem irqbalance, vypínal NCQ, disky jsou nové a v pořádku (smart), nepřehřívají se, server není přetěžován. Přitom provozuju ještě jeden server s téměř totožnou konfigurací, systémem a využitím, zde však k problémům nedochází.

Mám pocit, že se jedná určitě o nějaký SW problém, případně nějaké špatné nastavení, ale po půl roce hledání jsem stále na začátku. Napadlo mě nějaké porušení souborového systému, které se třeba přenáší mezi disky během synchronizace RAIDu. Formát disku a reinstalaci systému jsem zatím nedělal, nerad bych se do toho pouštěl, protože tam jedou VPS zákazníků.

Napadá prosím někoho něco, co jsem mohl přehlédnout?

Přikládám část messages log:

Oct  1 17:07:47 XXX kernel: ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct  1 17:07:47 XXX kernel: ata2.00: irq_stat 0x40000001
Oct  1 17:07:47 XXX kernel: ata2.00: cmd ea/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Oct  1 17:07:47 XXX kernel:          res 51/04:00:38:df:f7/00:00:00:00:00/a7 Emask 0x1 (device error)
Oct  1 17:07:47 XXX kernel: ata2.00: status: { DRDY ERR }
Oct  1 17:07:47 XXX kernel: ata2.00: error: { ABRT }
Oct  1 17:07:47 XXX kernel: ata2.00: configured for UDMA/133
Oct  1 17:07:47 XXX kernel: ata2: EH complete
Oct  1 17:07:47 XXX kernel: SCSI device sdb: 976773168 512-byte hdwr sectors (500108 MB)
Oct  1 17:07:47 XXX kernel: sdb: Write Protect is off
Oct  1 17:07:47 XXX kernel: SCSI device sdb: drive cache: write back

... toto se opakuje třeba 10x po sobě a obvykle končí rozpadem RAIDu:

Oct  1 20:27:47 XXX kernel: ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct  1 20:27:47 XXX kernel: ata2.00: irq_stat 0x40000001
Oct  1 20:27:47 XXX kernel: ata2.00: cmd 35/00:10:97:00:c4/00:00:38:00:00/e0 tag 0 dma 8192 out
Oct  1 20:27:47 XXX kernel:          res 51/10:10:97:00:c4/00:00:38:00:00/e0 Emask 0x81 (invalid argument)
Oct  1 20:27:47 XXX kernel: ata2.00: status: { DRDY ERR }
Oct  1 20:27:47 XXX kernel: ata2.00: error: { IDNF }
Oct  1 20:27:47 XXX kernel: ata2.00: configured for UDMA/133
Oct  1 20:27:47 XXX kernel: sd 1:0:0:0: SCSI error: return code = 0x08000002
Oct  1 20:27:47 XXX kernel: sdb: Current [descriptor]: sense key: Aborted Command
Oct  1 20:27:47 XXX kernel:     Add. Sense: Recorded entity not found
Oct  1 20:27:47 XXX kernel: 
Oct  1 20:27:47 XXX kernel: Descriptor sense data with sense descriptors (in hex):
Oct  1 20:27:47 XXX kernel:         72 0b 14 00 00 00 00 0c 00 0a 80 00 00 00 00 00 
Oct  1 20:27:47 XXX kernel:         38 c4 00 97 
Oct  1 20:27:47 XXX kernel: end_request: I/O error, dev sdb, sector 952369303
Oct  1 20:27:47 XXX kernel: raid1: Disk failure on sdb1, disabling device. 
Oct  1 20:27:47 XXX kernel: 	Operation continuing on 1 devices
Oct  1 20:27:47 XXX kernel: ata2: EH complete
Oct  1 20:27:47 XXX kernel: SCSI device sdb: 976773168 512-byte hdwr sectors (500108 MB)
Oct  1 20:27:47 XXX kernel: sdb: Write Protect is off
Oct  1 20:27:47 XXX kernel: SCSI device sdb: drive cache: write back

Odpovědi

[asdderwrqerew]

Skusal si vymenit kabelaz? Su tie disky v poriadku?

[Spyboy]

Měnil se celý server, tj. i backplane, zůstaly jen ty disky (které se za čas opět měnily). Je to 1U server, takže tam moc kabeláže není. Disky byly vždy měněny za úplně nové, WD Enterprise pro servery.

[michich]

Jsou ty chyby vidět i ve SMART logu? smartctl -a /dev/sdb

[Spyboy]

Je to nový disk, asi dva týdny v provozu, SMART mi přijde ok:

# smartctl -a /dev/sdb
smartctl version 5.38 [x86_64-redhat-linux-gnu] Copyright (C) 2002-8 Bruce Allen
Home page is http://smartmontools.sourceforge.net/

=== START OF INFORMATION SECTION ===
Device Model:     WDC WD5002ABYS-01B1B0
Serial Number:    WD-WCASY2045432
Firmware Version: 02.03B02
User Capacity:    500,107,862,016 bytes
Device is:        Not in smartctl database [for details use: -P showall]
ATA Version is:   8
ATA Standard is:  Exact ATA specification draft version not indicated
Local Time is:    Sun Oct  3 00:26:13 2010 CEST
SMART support is: Available - device has SMART capability.
SMART support is: Enabled

=== START OF READ SMART DATA SECTION ===
SMART overall-health self-assessment test result: PASSED

General SMART Values:
Offline data collection status:  (0x84) Offline data collection activity
                                        was suspended by an interrupting command from host.
                                        Auto Offline Data Collection: Enabled.
Self-test execution status:      (   0) The previous self-test routine completed
                                        without error or no self-test has ever
                                        been run.
Total time to complete Offline
data collection:                 (9480) seconds.
Offline data collection
capabilities:                    (0x7b) SMART execute Offline immediate.
                                        Auto Offline data collection on/off support.
                                        Suspend Offline collection upon new
                                        command.
                                        Offline surface scan supported.
                                        Self-test supported.
                                        Conveyance Self-test supported.
                                        Selective Self-test supported.
SMART capabilities:            (0x0003) Saves SMART data before entering
                                        power-saving mode.
                                        Supports SMART auto save timer.
Error logging capability:        (0x01) Error logging supported.
                                        General Purpose Logging supported.
Short self-test routine
recommended polling time:        (   2) minutes.
Extended self-test routine
recommended polling time:        ( 112) minutes.
Conveyance self-test routine
recommended polling time:        (   5) minutes.
SCT capabilities:              (0x303f) SCT Status supported.
                                        SCT Feature Control supported.
                                        SCT Data Table supported.

SMART Attributes Data Structure revision number: 16
Vendor Specific SMART Attributes with Thresholds:
ID# ATTRIBUTE_NAME          FLAG     VALUE WORST THRESH TYPE      UPDATED  WHEN_FAILED RAW_VALUE
  1 Raw_Read_Error_Rate     0x002f   200   200   051    Pre-fail  Always       -       0
  3 Spin_Up_Time            0x0027   158   158   021    Pre-fail  Always       -       5091
  4 Start_Stop_Count        0x0032   100   100   000    Old_age   Always       -       15
  5 Reallocated_Sector_Ct   0x0033   200   200   140    Pre-fail  Always       -       0
  7 Seek_Error_Rate         0x002e   200   200   000    Old_age   Always       -       0
  9 Power_On_Hours          0x0032   085   085   000    Old_age   Always       -       11546
 10 Spin_Retry_Count        0x0032   100   253   000    Old_age   Always       -       0
 11 Calibration_Retry_Count 0x0032   100   253   000    Old_age   Always       -       0
 12 Power_Cycle_Count       0x0032   100   100   000    Old_age   Always       -       15
192 Power-Off_Retract_Count 0x0032   200   200   000    Old_age   Always       -       10
193 Load_Cycle_Count        0x0032   200   200   000    Old_age   Always       -       15
194 Temperature_Celsius     0x0022   123   107   000    Old_age   Always       -       24
196 Reallocated_Event_Count 0x0032   200   200   000    Old_age   Always       -       0
197 Current_Pending_Sector  0x0032   200   200   000    Old_age   Always       -       0
198 Offline_Uncorrectable   0x0030   200   200   000    Old_age   Offline      -       0
199 UDMA_CRC_Error_Count    0x0032   200   200   000    Old_age   Always       -       0
200 Multi_Zone_Error_Rate   0x0008   200   200   000    Old_age   Offline      -       0

SMART Error Log Version: 1
No Errors Logged

SMART Self-test log structure revision number 1
No self-tests have been logged.  [To run self-tests, use: smartctl -t]


SMART Selective self-test log data structure revision number 1
 SPAN  MIN_LBA  MAX_LBA  CURRENT_TEST_STATUS
    1        0        0  Not_testing
    2        0        0  Not_testing
    3        0        0  Not_testing
    4        0        0  Not_testing
    5        0        0  Not_testing
Selective self-test flags (0x0):
  After scanning selected spans, do NOT read-scan remainder of disk.
If Selective self-test is pending on power-up, resume after 0 minute delay.

[AraxoN]

Mne niečo podobné tiež robilo s novými ovládačmi na ATA disky (Serial ATA and Parallel ATA drivers - sda, sdb, ...). Vrátil som sa späť ku starému ovládaču (ATA/ATAPI/MFM/RLL support (DEPRECATED) - hda, dhc, ...) a problém sa odstránil. Robilo to to, čo Tebe - chyby do logu a občasný rebuild či pád poľa SW RAID1. Nahoď nejaké staršie jadro, alebo si skompiluj nové s tým, že vyhodíš preč nové ovládače.

[Spyboy]

Když jsem zkoušel různé kernely, dostal jsem se k tomu, že jsem musel v BIOSu přenastavit disky ze SATA na IDE (jinak docházelo ke kernel panic, nyní vyřešeno bootováním s parametrem hda=noprobe) a systém viděl disky jako hda, hdb... Všechno jelo v pohodě, ale systém byl neuvěřitelně pomalý, jinak bych tam to IDE nechal...

Nyní jsem zkusil snížit rychlost SATA na 1.5 Gbps, uvidíme... ale není to dlouhodobé řešení...

[AraxoN]

A to sú SATA disky? Tak potom nič, mne to robilo len s PATA...

[Spyboy]

Ano, SATA disky. BTW. to snížení rychlosti bylo opravdu krátkodobé řešení, chyby jsou tu zase :-/

[AraxoN]

No... a používa sa správny ovládač? Autodetekcia nie je všemocná, alebo k ovládaču môžu existovať alternatívy. Pozri aký ovládač to pri štarte natiahlo (cez dmesg) a aký tam je v skutočnosti radič (cez lspci).

[michich]

Oct  1 17:07:47 XXX kernel: ata2.00: cmd ea/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Oct  1 17:07:47 XXX kernel:          res 51/04:00:38:df:f7/00:00:00:00:00/a7 Emask 0x1 (device error)
Oct  1 17:07:47 XXX kernel: ata2.00: status: { DRDY ERR }
Oct  1 17:07:47 XXX kernel: ata2.00: error: { ABRT }

Tady selhal ATA příkaz FLUSH CACHE EXT, číslo sektoru je 0xf7df38 = 16244536.

Vzhledem k tomu "device error" mě překvapuje, že tato událost není zároveň zaznamenána i ve SMART error logu.

... toto se opakuje třeba 10x po sobě a obvykle končí rozpadem RAIDu:

Jak rychle po sobě? A mění se postupně to číslo sektoru?

Oct  1 20:27:47 XXX kernel: ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct  1 20:27:47 XXX kernel: ata2.00: irq_stat 0x40000001
Oct  1 20:27:47 XXX kernel: ata2.00: cmd 35/00:10:97:00:c4/00:00:38:00:00/e0 tag 0 dma 8192 out
Oct  1 20:27:47 XXX kernel:          res 51/10:10:97:00:c4/00:00:38:00:00/e0 Emask 0x81 (invalid argument)
Oct  1 20:27:47 XXX kernel: ata2.00: status: { DRDY ERR }
Oct  1 20:27:47 XXX kernel: ata2.00: error: { IDNF }

Tady selhal příkaz WRITE DMA EXT, protože disk si myslí, že sektor s požadovanou adresou neexistuje.

To je ale podivné, protože 0x38c40097 = 952369303 je bezpečně pod hranicí velikosti disku:

Oct  1 20:27:47 XXX kernel: SCSI device sdb: 976773168 512-byte hdwr sectors (500108 MB)

[Spyboy]

Vzhledem k tomu "device error" mě překvapuje, že tato událost není zároveň zaznamenána i ve SMART error logu.

Proto si právě myslím, že se musí jednat o nějakou SW záležitost...

Jak rychle po sobě? A mění se postupně to číslo sektoru?

Pokud to vyskočí několikrát okamžitě za sebou, číslo sektoru zůstává stejné, jestliže se to zopakuje třeba po deseti minutách, pak je sektor jiný...

To je ale podivné, protože 0x38c40097 = 952369303 je bezpečně pod hranicí velikosti disku:

Přesně... a v tom RAIDu jsou totožné disky (typ, kapacita).

[Spyboy]

Tak jsem problém vyřešil upgradem ovzkernelu z 2.6.18 (stable) na 2.6.32 (devel). Týden se už zdá být vše ok. Sice pod novým kernelem (zatím) nefunguje cpulimit a každé VPS má tedy k dispozici celý výkon serveru, je to však lepší, než ty problémy s disky.

Všem moc děkuju za pomoc!