2012. március 3., szombat

Élménybeszámoló - Molylepke vadászat.

Noh. Eljött ez a nap is.. Végre ez a bug vadászat is lezárult, és hivatalos ticket is nyílt róla, így most már írhatok kicsit a részletekről..

A történet ott kezdődött amikor is az egyik HACMP clusterünk failover közben mondhatni "totál beakadt" -> A Resource group-ban (RG) definiált összes resource-t leadta a primary node, a secondary is elkezdte szépen átvenni, illetve az RG is szépen átment, de a folyamat során egy nem várt esemény is előjött: A primary node ez után teljesen elérhetetlen lett. Nézzük hirtelen mit is próbál az ember amikor ilyennel találkozik:
- Nyissunk újabb SSH kapcsolatot a gépre, hátha az előző megszakadt - No response...
- Oks.. elérhető a gép? Nézzünk rá egy ping tesztet - no ping reply.. (előtte volt)
- Jó.. Nézzünk be HMC-re. Az LPAR állapota "running". Tehát elvileg az LPAR megy.. De akkor meg mi a fene?
- Hátha csak a hálózat nyekkent meg. Menjünk be soros terminálról (vterm) - Semmi nem történik.

Ilyenkor ül ki az ember a kertbe, és elkezdi nagy, kikerekedett szemmel nézni a wattafákat, és azon filózni, hogy mikor szüretelheti le majd a fáról a vattát..

Összefoglalva: Az OS se előre, se hátra, az LPAR fut.. Nincs mit tenni.. Indítsuk újra a teljes LPAR-t.
Gép újraindul, log túrás.. Semmi, ami alapján el lehetne indulni.. Jó.. Akkor nézzük meg, hogy egyáltalán tudom e reprodukálni az esetet..
RG visszarak a primary node-ra (szépen visszamegy), majd újabb failover a primary-ról a secondary-re.. Ugyan az.. De legalább tudom, hogy reprodukálható az issue, ami azért sokkal jobb, mintha valami szellemet kéne kergetnem. Mázlimra a gépen szabadon lehetett egy ideig garázdálkodni, így kedvem szerint tesztelgethettem.

Kezdés képen szerettem volna kideríteni, hogy az RG-ben lévő applikációk okozzák e a problémát, vagy mélyebben kell keresgélni. Így fogtam magam, és a HACMP-ben definiált start/stop scripteket ideiglenesen kisöpörtem a színről (így csak a diszkek, LV-k, FS-ek, mount pointok, meg a service IP maradt) és megnéztem így is összeszakad e a gép.. Hát össze..

Jó, akkor nézzük tovább.. Következő ötletem az volt, hogy akkor ráengedek egy trace-t a gépre, úgy futtatok egy ilyen lecsupaszított failover-t, és akkor hátha észreveszem, hogy hol akad meg.. Sajna ez se nyert, mert amint a gép összerogyott a memóriában lévő trace bejegyzések se kerültek kiírásra, így a trace-em teljesen hiányos volt, és csak a standard folyamatok voltak benne, amit amúgy is vár az ember.

1-2 felesleges kísérlet után eljutottam addig, hogy mivel a hálózatom egy idő után úgy is elmegy, így azon keresztül felesleges bármit nézzek, mert simán előfordulhat, hogy a hálózat megszűnése után még a gép csinál valamit a háttérben. Tehát bejelentkeztem virtuális terminálon keresztül (mondván, hogy ami ott van azt csak látnom kell), és úgy elkezdtem monitorozni, hogy a gép meddig jut.. Furcsa mód a HA (illetve az OS) az alábbi parancs után dőlt le:

ifconfig en2 delete ${HACMP_MANAGED_SERVICE_IP_ADDRESS}

Kicsit furcsálltam a dolgot, de gondoltam üsse kutya, mit veszíthetek, ha ezt a lehetőséget is megnézem. Gép újraindul, HA RG ismét a helyére, majd csodálkozva konstatáltam, hogy a fenti parancs futtatásával a gép tényleg ugyan úgy bedől, annak rendje és módja szerint..

Ez egy részről jót jelentett, mert innentől tudtam, hogy a HACMP-nek köze nincs az issue-hoz, más részről viszont bajban voltam, mert az ifconfig-nak ilyet elméletileg még véletlenül se kéne okoznia (az tuti, hogy ezt semmiféle dokumentációban nem említik :))

Ez volt az a pont amikor ez már software call-ért kiáltott.. Tehát hivatalosan is jelentettem a hibát az IBM-es fejlesztők felé, hogy akkor kérem ennek tessék utánanézni. A kezdeti adminisztrációs útvesztőkön, és issue leírás+hiba bizonyítás után aztán a hivatalos IBM supportal eljutottunk addig, hogy itt valami tényleg nem kóser. Első körben ők már egy full system dump-ot kértek tőlem -az után, hogy a gép összecsuklott- hogy megnézzék, hogy a memóriában mi van. Azt analizálva aztán kijött, hogy az összes LPAR-hoz assignolt processzor szál LOCK állapotban van, tehát nem mozdul senki semerre..

Ez persze megmagyarázza, hogy a gép ez után miért nem csinált semmit, de azt nem, hogy hogy jutott el eddig az állapotig. A következő lépésként a fejlesztők küldtek nekem egy kissé átberhelt kernelt, amiben az elérhető összes debug opciót bekapcsolták, hogy aztán az a memóriában (és így a dumpban) is könnyebben követhető legyen.

Az új kernelt életbe léptetve (majd a gépet ismételten megakasztva) immár látható volt, hogy routing lock ált be, tehát kernel szinten volt valami megkergülve. Ez már elég volt a fejlesztőknek, hogy megfelelően e tudják szűkíteni a lehetséges problémák forrását, és ki tudják ténylegesen debugolni, hogy honnan is ered a hiba.

Rövidesen meg is született az eredmény - "A" patch. Megkaptam, telepítettem, és csodák csodájára működött.. Öröm és bóduttá.. Na jó.. Nem teljesen.. Volt még 1-2 dolog amit meg kellett oldani.
-> A patch csak AIX 5.3 TL12 SP04 alá készült el. Sajna a latest SP 05ön állt, és ezen a rendszeren is hamarosan telepíteni kellett, ám mint kiderült az SP05 is érintett volt az issue kapcsán. Sőt mi több, a 6.1es AIX is (TL07,SP2 a latest). Így arra kértem a fejlesztőket, hogy a hivatalos úton olvasszák be ezt a patch-et az érintett AIX verziókba, hogy aztán a következő TL/SP-kben már benne is lehessen.

Így született aztán meg a IV16037-es patch (IBM ID szükséges a megtekintéséhez)

Ha ne adj isten valaki más is hasonló problémákba ütközik a közeljövőben (amíg a fix nem lesz elérhető hivatalosan), akkor némi kis segítség a gyors probléma megoldáshoz:
- teljes system dump force-olása a HMC-ről restartal egybekötve
- Dump analízis kdb-vel. A stack nálam így nézett ki:
pvthread+031300 STACK:
[0000932C].unlock_enable_mem+000020 ()
[00204F50]rt_setgate+0001F8 (??, ??, ??)
[043D6A08]in_ifscrub+000488 (??, ??)
[043D8050]in_control+0009A8 (??, ??, ??, ??)
[04436B38]udp_usrreq+000214 (??, ??, ??, ??, ??)
[0020E7F4]ifioctl+00075C (??, ??, ??)
[0025FDFC]soo_ioctl+000494 (??, ??, ??)
[004A8968]common_ioctl+0000C0 (??, ??, ??, ??)
[00003810].svc_instr+000110 ()
[kdb_get_memory] no real storage @ 2FF22390
[D03B1D14]D03B1D14 ()
- Ha ilyesmi, vagy a ticketben leírthoz hasonló stack-el találkozol, nyiss egy SW call-t az IBM felé, és hivatkozz a fenti fix-re.
- Ők persze ugyan úgy el fogják kérni a dump-ot, hogy megbizonyosodjanak róla, hogy a 2 eset valóban 1 tőről származik e. Ha úgy találják, hogy igen, akkor elérhetővé teszik számodra a patch-et.