EX-Server mit VMware ESXi und LSI MegaRAID? Wöchentlich Kernel-Log checken!

Hetzner liefert die MegaRAIDs in den EX-Servern mit vorkonfiguriertem wöchentlichem Konsistenzcheck aus. Der Zeitpunkt kann variieren; bei meinen beiden Servern startet er in der Nacht von Freitag auf Samstag, um 3 Uhr UTC (4 Uhr aktuelle Deutschlandzeit). Er dauert üblicherweise bis 10:00-10:30, je nach sonstiger Festplattenlast.
Der Check hinterläßt seine Spuren im Kernel-Log. Ein Blick in dieses Log kann also – unabhängig von sonstigem Monitoring – verraten, ob mit den Platten alles okay ist. Der Kernel-Log findet sich in /scratch/log/vmkernel.log auf dem ESXi-Host.
Der Ablauf sieht im Idealfall gekürzt so aus:
[bash]
2013-03-23T03:03:14.749Z cpu1:2660)<6>megasas_hotplug_work[7]: aen event code 0x0027
2013-03-23T03:03:19.057Z cpu0:2657)<6>megasas_hotplug_work[7]: aen event code 0x0042
2013-03-23T03:03:19.111Z cpu5:2650)<6>megasas_hotplug_work[7]: aen event code 0x0023
2013-03-23T03:03:19.112Z cpu5:2654)<6>megasas_hotplug_work[7]: aen event code 0x0041
2013-03-23T03:04:24.358Z cpu0:2649)<6>megasas_hotplug_work[7]: aen event code 0x0041
2013-03-23T03:05:17.458Z cpu0:2649)<6>megasas_hotplug_work[7]: aen event code 0x0041
[…Jede Menge 0x0041…]
2013-03-23T09:10:13.970Z cpu0:2646)<6>megasas_hotplug_work[7]: aen event code 0x0041
2013-03-23T09:11:50.713Z cpu0:2657)<6>megasas_hotplug_work[7]: aen event code 0x0041
2013-03-23T09:13:19.215Z cpu0:2660)<6>megasas_hotplug_work[7]: aen event code 0x0041
2013-03-23T09:13:24.769Z cpu4:2652)<6>megasas_hotplug_work[7]: aen event code 0x003a[/bash]
Der exakte Wortlaut der Meldungen kann sich, je nach ESXi-Version, unterscheiden. Ältere Versionen fügen z.B. zwischen die “aen event” Zeilen jeweils noch eine andere Zeile ein. Wichtig sind die Eventcodes. Diese bedeuten:
[bash]0x0027 – Partrol Read started
0x0042 – Consistency Check started
0x0023 – Patrol Read complete
0x0041 – Consistency Check progress
0x003a – Consistency Check done[/bash]
Zwischendurch können “Host Busy” Fehlermeldungen des Controllers erfolgen. Diese sehen oft dramatisch aus (Beispiel s.u.), haben aber erfahrungsgemäß keine negativen Folgen.
Aus aktuellem Anlaß: Sollte der Strom von 0x0041-Events im Kernel-Log plötzlich abreißen oder Ihr feststellen, daß zu sonstigen Gelegenheiten nichts mehr in den Logs landet, kann dieses Kommando helfen:
[bash]esxcli system syslog reload[/bash]
Zusätzlich könnt Ihr, falls Ihr das MegaCLI installiert habt, mit folgendem Kommando den Fortschritt eines laufenden Checks, und den Status des Arrays, abfragen:
[bash]cd /opt/lsi/MegaCLI
./MegaCli -LDCC -showprog -LALL -AALL
./MegaCli -ldinfo -l0 -aall[/bash]
Ebenso kann man mit MegaCLI den Zeitpunkt des Checks konfigurieren, mit “MegaCli -AdpCcSched”; das habe ich aber noch nicht ausprobiert und möchte daher keine verbindlichen Hinweise dazu geben.
Falls Ihr andere Statuscodes des Consistency Check im Kernel-Log vorfindet, könnt Ihr in der hier verlinkten PDF-Datei schauen. Dort steht drin, was sie zu bedeuten haben.
https://data.virtpro.eu/vmware/lsi-megaraid/A_Event_Info.pdf
[bash]2013-03-23T09:47:14.262Z cpu4:6362240)megasas: ABORT sn 651094276 cmd=0x2a retries=0 tmo=0
2013-03-23T09:47:14.262Z cpu4:6362240)<5>0 :: megasas: RESET -651094276 cmd=2a retries=0
2013-03-23T09:47:14.262Z cpu4:6362240)megaraid_sas: HBA reset handler invoked without an internal reset condition.
2013-03-23T09:47:16.733Z cpu6:2054)WARNING: LinScsi: SCSILinuxQueueCommand:1175:queuecommand failed with status = 0x1055 Host Busy vmhba1:2:0:0 (driver name: LSI Logic SAS based MegaRAID driver) – Message repeated 1218 times
2013-03-23T09:47:16.733Z cpu6:2054)ScsiDeviceIO: 2309: Cmd(0x41240071b200) 0x8a, CmdSN 0xeb from world 4836 to dev "naa.600605b00413718016b58fa5040e8e96" failed H:0x0 D:0x8 P:0x0 Possible sense data: 0x0 0x0 0x0.
2013-03-23T09:47:16.733Z cpu6:2054)ScsiDeviceIO: 2309: Cmd(0x41240079d2c0) 0x8a, CmdSN 0xf3 from world 4836 to dev "naa.600605b00413718016b58fa5040e8e96" failed H:0x0 D:0x8 P:0x0 Possible sense data: 0x0 0x0 0x0.
2013-03-23T09:47:16.733Z cpu6:2054)ScsiDeviceIO: 2309: Cmd(0x412400729e80) 0x2a, CmdSN 0xfffffadf9b655130 from world 4523 to dev "naa.600605b00413718016b58fa5040e8e96" failed H:0x0 D:0x8 P:0x0 Possible sense data: 0x0 0x0 0x0.
2013-03-23T09:47:16.733Z cpu6:2054)ScsiDeviceIO: 2309: Cmd(0x412400730100) 0x2a, CmdSN 0xfffffadf9b8d1830 from world 4523 to dev "naa.600605b00413718016b58fa5040e8e96" failed H:0x0 D:0x8 P:0x0 Possible sense data: 0x0 0x0 0x0.
2013-03-23T09:47:16.733Z cpu6:2054)ScsiDeviceIO: 2309: Cmd(0x41240078bac0) 0x2a, CmdSN 0xcd from world 4568 to dev "naa.600605b00413718016b58fa5040e8e96" failed H:0x0 D:0x8 P:0x0 Possible sense data: 0x0 0x0 0x0.
2013-03-23T09:47:16.733Z cpu6:2054)ScsiDeviceIO: 2309: Cmd(0x412400708cc0) 0x2a, CmdSN 0xc7 from world 4568 to dev "naa.600605b00413718016b58fa5040e8e96" failed H:0x0 D:0x8 P:0x0 Possible sense data: 0x0 0x0 0x0.
2013-03-23T09:47:17.297Z cpu6:6362240)<7>megaraid_sas: megasas_wait_for_outstanding: line 2131: AFTER HBA reset handler invoked without an internal reset condition: took 3 seconds. Max is 180.
2013-03-23T09:47:17.297Z cpu6:6362240)megaraid_sas: no more pending commands remain after reset handling.
2013-03-23T09:47:17.297Z cpu6:6362240)<5>megasas: reset successful
2013-03-23T09:47:17.307Z cpu7:416676)ScsiDeviceIO: 2291: Cmd(0x41240071b200) 0x8a, CmdSN 0xeb from world 4836 to dev "naa.600605b00413718016b58fa5040e8e96" failed H:0x8 D:0x0 P:0x0
2013-03-23T09:47:17.307Z cpu7:416676)ScsiDeviceIO: 2291: Cmd(0x41240079d2c0) 0x8a, CmdSN 0xf3 from world 4836 to dev "naa.600605b00413718016b58fa5040e8e96" failed H:0x8 D:0x0 P:0x0
2013-03-23T09:47:17.307Z cpu7:416676)ScsiDeviceIO: 2291: Cmd(0x41240075d980) 0x2a, CmdSN 0xca2a1e from world 2056 to dev "naa.600605b00413718016b58fa5040e8e96" failed H:0x8 D:0x0 P:0x0
2013-03-23T09:47:17.307Z cpu7:416676)ScsiDeviceIO: 2291: Cmd(0x4124007c93c0) 0x2a, CmdSN 0xca2a1f from world 2056 to dev "naa.600605b00413718016b58fa5040e8e96" failed H:0x8 D:0x0 P:0x0
2013-03-23T09:47:17.307Z cpu7:416676)ScsiDeviceIO: 2291: Cmd(0x412400775880) 0x2a, CmdSN 0xca2a22 from world 2056 to dev "naa.600605b00413718016b58fa5040e8e96" failed H:0x8 D:0x0 P:0x0
2013-03-23T09:47:17.307Z cpu4:5533)HBX: 2313: Waiting for timed out [HB state abcdef02 offset 4157440 gen 169 stampUS 8771157754484 uuid 50c7a484-d2cbdc06-4f03-5404a6a68f0e jrnl <FB 1794200> drv 14.54] on vol ‘Vega_Store’
2013-03-23T09:47:17.307Z cpu0:4059)HBX: 2313: Waiting for timed out [HB state abcdef02 offset 4157440 gen 169 stampUS 8771157754484 uuid 50c7a484-d2cbdc06-4f03-5404a6a68f0e jrnl <FB 1794200> drv 14.54] on vol ‘Vega_Store’
2013-03-23T09:47:17.398Z cpu7:2067)HBX: 231: Reclaimed heartbeat for volume 4f398b88-fbf1b358-ed03-5404a6a68f0e (Vega_Store): [Timeout] [HB state abcdef02 offset 4157440 gen 169 stampUS 8771170887971 uuid 50c7a484-d2cbdc06-4f03-5404a6a68f0e jrnl <FB 179$[/bash]

VMware ESXi 5.0 Known Issues at Hetzner

Keine RAID-Informationen mehr im vSphere Client

Von Zeit zu Zeit kann es vorkommen, daß der Hardware Monitor im vSphere Client keine Informationen mehr über den RAID-Controller anzeigt. Möglicherweise verschwinden die einzelnen Einträge nach und nach, bis der Controller irgendwann gar nicht mehr auftaucht.
Dieser Fehler könnte mit der aktuellen Version des CIM/SMIS Providers von LSI behoben worden sein.
Ansonsten gibt es einen Workaround. Wir loggen an der SSH-Konsole des ESXi ein und führen diesen Befehl aus:
[bash]/etc/init.d/sfcbd-watchdog restart >/scratch/log/sfcbd.log 2>&1[/bash]
Dies startet den SFCBD (Small Footprint CIM Broker Daemon, zuständig fürs Einsammeln und Abfragen der Sensordaten) neu. Die Umleitung in eine Dummy-Logdatei ist nötig, da der Watchdog ansonsten das Terminal alloziert hält, was zu dem Fehler “Warnungen “PTY Would block” im Kernel-Log” führt.

Warnungen “PTY Would block” im Kernel-Log

Symptom: Im Kernel-Log /scratch/log/vmkernel.log tauchen im Minutentakt Warnungen dieser Form auf:
[bash]Failed to crossdup fd 1, /dev/char/pty/t1 type CHAR: Would block[/bash]
Dies liegt daran, daß ein per SSH-Konsole ausgeführtes Kommando seine Verbindung zum virtuellen Terminal nicht geschlossen hat und versucht, dort Ausgaben zu tätigen. Wurde die Shell inzwischen geschlossen, existiert das Terminal nicht mehr.
Oft wurde der SFCBD-Watchdog ohne Umleitung in ein Dummy-File neugestartet, siehe “Keine RAID-Informationen mehr im vSphere Client”, oder aber die Systemdienste mittels/sbin/services.sh restart neugestartet, was den SFCBD-Watchdog einschließt.

Keine neuen Einträge in Logs

Falls ab einem gewissen Zeitpunkt keine Einträge mehr in die Logs (Syslog, Kernel-Log etc.) geschrieben werden, könnte einfach der Syslog-Daemon abgestürzt sein. Dies läßt sich auf der SSH-Konsole beheben durch einen Neustart des Syslog-Daemon:
[bash]esxcli system syslog reload[/bash]

Fehler beim Statusabruf der BBU im Syslog

Symptom: Im Syslog /scratch/log/syslog tauchen im Minutentakt solche Meldungen auf:
[bash]
2012-09-28T13:00:50Z sfcb-LSIESG_SMIS13_HHR[10850792]: INTERNAL StoreLibFacade::fireStorelibCommand – caller StoreLibFacadeMR::getBBUStatus, ProcessLibCommandCall failed, returnValue = 0x22
2012-09-28T13:00:50Z sfcb-LSIESG_SMIS13_HHR[10850792]: INTERNAL BBU::refresh: Failed BBUStatus
2012-09-28T13:00:50Z sfcb-LSIESG_SMIS13_HHR[10850792]: INTERNAL StoreLibFacade::fireStorelibCommand – caller StoreLibFacadeMR::getBBUCapacityInfo, ProcessLibCommandCall failed, returnValue = 0x22
2012-09-28T13:00:50Z sfcb-LSIESG_SMIS13_HHR[10850792]: INTERNAL BBU::refresh:Failed CapacityInfo
2012-09-28T13:00:50Z sfcb-LSIESG_SMIS13_HHR[10850792]: INTERNAL StoreLibFacade::fireStorelibCommand – caller StoreLibFacadeMR::getBBUDesignInfo, ProcessLibCommandCall failed, returnValue = 0x22
2012-09-28T13:00:50Z sfcb-LSIESG_SMIS13_HHR[10850792]: INTERNAL BBU::refresh:Failed DesignInfo
2012-09-28T13:00:50Z sfcb-LSIESG_SMIS13_HHR[10850792]: INTERNAL StoreLibFacade::fireStorelibCommand – caller StoreLibFacadeMR::getBBUProperties, ProcessLibCommandCall failed, returnValue = 0x22
2012-09-28T13:00:50Z sfcb-LSIESG_SMIS13_HHR[10850792]: INTERNAL BBU::refresh:Failed Properties[/bash]
“BBU” bedeutet “Backup Battery Unit”, gemeint ist eine Backupbatterie im RAID-Controller.
Ältere Versionen des LSI MegaRAID CIM-Providers haben einen Fehler, der diese Meldungen produziert. Sie sind im wesentlichen harmlos. Update auf eine aktuelle Version sollte das Problem komplett beseitigen.

Software und Update Downloads

LSI Downloads: http://www.lsi.com/products/storagecomponents/Pages/MegaRAIDSAS9260-4i.aspx
MegaCLI – 5.5 http://www.lsi.com/downloads/Public/MegaRAID%20Common%20Files/8.07.06_MegaCLI.zip
VMWare SMIS Provider VIB – 5.5 http://www.lsi.com/downloads/Public/MegaRAID%20Common%20Files/00_34_V0_01_SMIS_VMware_Installer.zip
Firmware 4.9  http://www.lsi.com/downloads/Public/MegaRAID%20Common%20Files/12.12.0-0139_SAS_2108_Fw_Image_APP2.130.373-2022.zip
Die Aktuellen Patches gibt es bei VMware: http://www.vmware.com/patchmgr/download.portal
https://data.virtpro.eu/
für wget Bitte http://dl.virtpro.eu auf ESXi benutzen, da ESXi kein http(s) kann.

Informations Anzeige mit MegaCLI

[bash]
/opt/lsi/MegaCLI # ./MegaCli -AdpAllInfo -aAll
==============================================================================
Versions
================
Product Name : LSI MegaRAID SAS 9260-4i
Serial No : SV22820638
FW Package Build: 12.12.0-0111
Mfg. Data
================
Mfg. Date : 07/12/12
Rework Date : 00/00/00
Revision No : 86B
Battery FRU : N/A
Image Versions in Flash:
================
FW Version : 2.130.353-1663
BIOS Version : 3.24.00_4.12.05.00_0x05160000
Preboot CLI Version: 04.04-020:#%00009
WebBIOS Version : 6.0-49-e_45-Rel
NVDATA Version : 2.09.03-0032
Boot Block Version : 2.02.00.00-0000
BOOT Version : 09.250.01.219
Pending Images in Flash
================
None
PCI Info
================
Controller Id : 0000
Vendor Id : 1000
Device Id : 0079
SubVendorId : 1000
SubDeviceId : 9260
Host Interface : PCIE
ChipRevision : B4
Number of Frontend Port: 0
Device Interface : PCIE
…[/bash]
 
[bash]
/opt/lsi/MegaCLI # ./MegaCli -LDInfo -L0 -a0
Adapter 0 — Virtual Drive Information:
Virtual Drive: 0 (Target Id: 0)
Name :
RAID Level : Primary-1, Secondary-0, RAID Level Qualifier-0
Size : 2.728 TB
Is VD emulated : Yes
Mirror Data : 2.728 TB
State : Optimal
Strip Size : 64 KB
Number Of Drives : 2
Span Depth : 1
Default Cache Policy: WriteBack, ReadAhead, Cached, Write Cache OK if Bad BBU
Current Cache Policy: WriteBack, ReadAhead, Cached, Write Cache OK if Bad BBU
Default Access Policy: Read/Write
Current Access Policy: Read/Write
Disk Cache Policy : Disk’s Default
Encryption Type : None
Is VD Cached: No
Exit Code: 0x00[/bash]
 
[bash]
/opt/lsi/MegaCLI # ./MegaCli -PDList -Aall
Adapter #0
Enclosure Device ID: 252
Slot Number: 0
Drive’s postion: DiskGroup: 0, Span: 0, Arm: 1
Enclosure position: N/A
Device Id: 5
WWN: 5000c5004dfd1e39
Sequence Number: 2
Media Error Count: 0
Other Error Count: 0
Predictive Failure Count: 0
Last Predictive Failure Event Seq Number: 0
PD Type: SATA
Raw Size: 2.728 TB [0x15d50a3b0 Sectors]
Non Coerced Size: 2.728 TB [0x15d40a3b0 Sectors]
Coerced Size: 2.728 TB [0x15d400000 Sectors]
Emulated Drive: Yes
Firmware state: Online, Spun Up
Commissioned Spare : No
Emergency Spare : No
Device Firmware Level: CC43
Shield Counter: 0
Successful diagnostics completion on : N/A
SAS Address(0): 0x4433221103000000
Connected Port Number: 1(path0)
Inquiry Data: Z1F0XS5MST3000DM001-1CH166 CC43
FDE Capable: Not Capable
FDE Enable: Disable
Secured: Unsecured
Locked: Unlocked
Needs EKM Attention: No
Foreign State: None
Device Speed: 6.0Gb/s
Link Speed: 6.0Gb/s
Media Type: Hard Disk Device
Drive Temperature :33C (91.40 F)
PI Eligibility: No
Drive is formatted for PI information: No
PI: No PI
Port-0 :
Port status: Active
Port’s Linkspeed: 6.0Gb/s
Drive has flagged a S.M.A.R.T alert : No
Enclosure Device ID: 252
Slot Number: 1
Drive’s postion: DiskGroup: 0, Span: 0, Arm: 0
Enclosure position: N/A
Device Id: 4
WWN: 5000c5004dfd1214
Sequence Number: 2
Media Error Count: 0
Other Error Count: 0
Predictive Failure Count: 0
Last Predictive Failure Event Seq Number: 0
PD Type: SATA
Raw Size: 2.728 TB [0x15d50a3b0 Sectors]
Non Coerced Size: 2.728 TB [0x15d40a3b0 Sectors]
Coerced Size: 2.728 TB [0x15d400000 Sectors]
Emulated Drive: Yes
Firmware state: Online, Spun Up
Commissioned Spare : No
Emergency Spare : No
Device Firmware Level: CC43
Shield Counter: 0
Successful diagnostics completion on : N/A
SAS Address(0): 0x4433221102000000
Connected Port Number: 0(path0)
Inquiry Data: Z1F0XRVMST3000DM001-1CH166 CC43
FDE Capable: Not Capable
FDE Enable: Disable
Secured: Unsecured
Locked: Unlocked
Needs EKM Attention: No
Foreign State: None
Device Speed: 6.0Gb/s
Link Speed: 6.0Gb/s
Media Type: Hard Disk Device
Drive Temperature :32C (89.60 F)
PI Eligibility: No
Drive is formatted for PI information: No
PI: No PI
Port-0 :
Port status: Active
Port’s Linkspeed: 6.0Gb/s
Drive has flagged a S.M.A.R.T alert : No
Exit Code: 0x00[/bash]
 
[bash]/opt/lsi/MegaCLI # ./MegaCli -PDList -Aall | egrep "Enclosure Device ID:|Slot Number:|Inquiry Data:|Error Count:|state"
Enclosure Device ID: 252
Slot Number: 0
Media Error Count: 0
Other Error Count: 0
Firmware state: Online, Spun Up
Inquiry Data: Z1F0XS5MST3000DM001-1CH166 CC43
Enclosure Device ID: 252
Slot Number: 1
Media Error Count: 0
Other Error Count: 0
Firmware state: Online, Spun Up
Inquiry Data: Z1F0XRVMST3000DM001-1CH166 CC43[/bash]