Rutin feladatnak indult, mint megannyi más dolog a munkám során: Egy HACMP cluster alá kell új diszkeket, illetve VG-ket definiálni, a hozzájuk tartozó filerendszerekkel együtt.
A dolog ugye annyira nem is nehéz:
- Adjuk hozzá az új LUN-okat a node-okhoz storage-ról (jelen esetben VIO-ról de részletkérdés)
- Ez után bizonyosodjunk meg róla, hogy minden LUN-nak van saját PVID-ja (enélkül ugyan is a HA nem fog törődni az új diszkekkel)
- Konfigoljuk fel a cluster alatt az új device-okat a "Discover HACMP-related Information from Configured Nodes" parancsal
- Amint megvan hozzunk létre egy új VG-t a HA alatt (Tegyünk egy szivességet magunknak és legyen scalable :))
- Majd alá a szükséges LV-ket
- Illetve az FS-eket is (újabb tipp: INLINE logolás sokat segít)
- Ez után extended verification-el nézzük meg, hogy a cluster konzisztensen lát e mindent
Ez persze mind online megy, és semmiféle outage-el nem jár.. A nagykönyv szerint..
Épp ezért is lepődtem meg, amikor a gépen futó alkalmazások adminjai egyszerre sikítottak fel, hogy mi a fene is történt, mert a gépen futó több adatbázis, és alkalmazás is egyszerre ficcent el..
Az applikációs (DB2) logokból nyomban ki is jön, hogy mi az első nyom amin el tudunk indulni:
SIGKILL.. még jobb.. oks.. akkor nézzük a hacmp.out-ot:FUNCTION: DB2 UDB, oper system services, sqloEDUSIGCHLDHandler, probe:50 DATA #1 :An EDU with process id 2121840 was terminated by a SIGKILL signal. It is not possible to produce a trap file in this case.
+7101 Reference string: Thu.Nov.17.14:55:10.GMT.2011.cl_deactivate_fs.All_filesystems.app_rg.ref
+7102 app_rg:cl_deactivate_fs[476] [[ false = true ]]
+7103 app_rg:cl_deactivate_fs[482] [ sequential = parallel ]
+7104 app_rg:cl_deactivate_fs[492] [ REAL = EMUL ]
+7105 app_rg:cl_deactivate_fs[497] fs_umount /var/mqm cl_deactivate_fs app_rg_deactivate_fs.tmp
+7106 app_rg:cl_deactivate_fs[4] FS=/var/mqm
+7107 app_rg:cl_deactivate_fs[5] PROGNAME=cl_deactivate_fs
+7108 app_rg:cl_deactivate_fs[6] TMP_FILENAME=app_rg_deactivate_fs.tmp
+7109 app_rg:cl_deactivate_fs[7] STATUS=0
+7110 app_rg:cl_deactivate_fs[10] app_rg:cl_deactivate_fs[10] lsfs -c /var/mqm
+7111 app_rg:cl_deactivate_fs[10] tail -1
+7112 app_rg:cl_deactivate_fs[10] cut -c6-
+7113 app_rg:cl_deactivate_fs[10] cut -d: -f2
+7114 lv=lvmqm
+7115 app_rg:cl_deactivate_fs[12] [ 0 -ne 0 ]
+7116 app_rg:cl_deactivate_fs[23] mount
+7117 app_rg:cl_deactivate_fs[23] fgrep -s -x /dev/lvmqm
+7118 app_rg:cl_deactivate_fs[23] awk { print $1 }
+7119 app_rg:cl_deactivate_fs[25] [ 0 -eq 0 ]
+7120 app_rg:cl_deactivate_fs[38] fuser -k -u -x /dev/lvmqm
+7121 /dev/lvmqm: 397382k(mqm) 438366(mqm) 454864k(mqm) 524364k(mqm) 569576k(mqm) 647266(mqm) 704590(mqm) 860414(mqm) 929994k(mqm) 991310k(mqm) 1122476k(mqm) 1126602k(mqm) 1138738k(mqm) 1232932(mqm) 1314926(mqm) 1335538k(mqm) 1556634k(mqm) 1675270k(mqm) 1708056k(mqm) 1835182(mqm) 1900648(mqm) 1904850k(mqm) 1949698k(mqm) 2465990k(mqm) 3268838k(mqm) 3547274k(mqm)+3123 Nov 17 14:55:05 EVENT START: reconfig_resource_release_primary
+3124
+3125 + [[ high = high ]]
+3126 + version=1.90
+3127 + echo arguments:
+3128 arguments:
+3129 + DCD=/etc/es/objrepos
+3130 + SCD=/usr/es/sbin/cluster/etc/objrepos/stage
+3131 + ACD=/usr/es/sbin/cluster/etc/objrepos/active
+3132 + set -a
+3133 + cllsparam -n node1
+3134 + ODMDIR=/usr/es/sbin/cluster/etc/objrepos/active
+3135 + eval NODE_NAME=node1 VERBOSE_LOGGING=high PS4='${GROUPNAME:-}:${PROGNAME}[$LINENO] ' DEBUG_LEVEL=Standard LC_ALL='C'
+3136 + NODE_NAME=node1 VERBOSE_LOGGING=high PS4=${GROUPNAME:-}:${PROGNAME}[$LINENO] DEBUG_LEVEL=Standard LC_ALL=C
+3137 :reconfig_resource_release_primary[767] set +aIgen, erre emlékszel.. Itt futtattam a clverify-cationt.. De 2 dolog is nyomban feltűnik:+54051 Verification has completed normally. +54052 +54053 clsnapshot: Creating file /usr/es/sbin/cluster/snapshots/active.0.odm... +54054 +54055 clsnapshot: Succeeded creating Cluster Snapshot: active.0. +54056 +54057 cldare: Requesting a refresh of the Cluster Manager... +54058 +54059 ---- end ---- +54060 +54061 [Nov 17 2011, 14:55:05]
- A cldare-t refreshelte a verification a legvégén.
- Ennek időpontja 14.55.05 volt, ami pontosan megegyezik a hacmp.out-ban lévő "EVENT START: reconfig_resource_release_primary" esemény időpontjával..
Ergo itt tényleg lehet valami kapcsolat.. Kicsit nézelődve meg is találtam mi az:
IY82802 - https://www-304.ibm.com/support/docview.wss?uid=isg1IY82802
* USERS AFFECTED:
* Users of HACMP R530 with the cluster.es.server.events fileset
* at the 5.3.0.2 or 5.3.0.3 level.
Ez most komoly??
Jah igen.. komoly..server@root # lslpp -l cluster.es.server.events |grep cluster.es.server.events|sort -u cluster.es.server.events 5.3.0.0 COMMITTED ES Server Events cluster.es.server.events 5.3.0.3 COMMITTED ES Server Events
Összefoglalva: Sikerült belefutnom egy 2007es bug-ba, ami egy egyszerű online művelet során ámokfutásba kezdett, és legyilkolt minden HA alatt futó applikációt. Hogy hogy sikerült egy ekkora bogárnak több mint 4 évig megélnie a rendszeren? Nos.. Így vettük át az előző tulajtól, és marha módon feltételeztük, hogy ő figyelt rá eléggé.. Hiba volt..
For the record:
- Átvett rendszer alatt tessék mindent átnézni (tudom, könnyű mondani), különös tekintettel a hiányzó javításokra (főleg ha azok ilyen kritikusak)
- Ez a bejegyzés azért született, hogy más is tanulhasson belőle. Nem vagyok büszke rá, hogy egy ilyen kritikus "csontvázat" csak akkor sikerült észlelnünk, amikor az már kibújt a szekrényből. Mentegetőzhetnék azzal, hogy a "ha működik ne nyúlj hozzá"
elv érvényesül általában, vagy, hogy "nincs idő a pro-aktivitásra" de mindegyik csak üres kifogás lenne saját magammal szemben is. Legyen ez egy szükséges felhívás mind magam, mind a te (kedves olvasó) részedre, hogy azért fél,1 évente tessék az ilyen dolgokat is átnézni, és igen is kell ezekre is időt találni*
* Megjegyzem, hogy sajna ezzel se leszünk képesek elkerülni a komoly hibákat 100%-ban, viszont a már ismert hibákból adódó lehetséges problémákat legalább ki tudjuk küszöbölni
