A következő címkéjű bejegyzések mutatása: bug. Összes bejegyzés megjelenítése
A következő címkéjű bejegyzések mutatása: bug. Összes bejegyzés megjelenítése

2013. augusztus 10., szombat

"Még jőni kell, még jőni fog egy jobb core.." - Népköltés..

Majd 3 hónap.. Ennyi ideje nem írtam erre e blogra semmit..
Nem azért mert szabadságon voltam, vagy mert elfelejtettem.. Egyszerűen nem volt miről írni ami erre a blogra tartozott volna (az, hogy hogyan lehet Monitoringot migrálni, meg HMC-t 4.4-rol 7.7re felupgrade-elni nem olyan jó alapanyag higgyétek el), vagy pedig szimplán olyan természetű volt amit a jelenlegi szerződésem nem enged meg (pedig jó lenne írni egy cikket róla.. ki tudja, majd 1x talán).
Hiába, ez van ha az ember nem foglalkozhat a hétköznapi adminisztrációval, hanem csak "project tevékenységekkel"

Ami azt illeti, a mostani téma se olyan nagy eresztés, de gondoltam azért még valakinek így is jól jöhet még ez.

Na szóval a helyzet: Adott egy core file a rendszeren (VIO szerver), ráadásul meglehetősen nagy méretben:

server@root # ls -l /core
-rw------- 1 root system 829566976 Jul 27 19:45 core
Igen, ez egy majd 800 MB-os darab, ráadásul a / FS alatt, amit a rendszer adminok nem véletlenül utálnak, legfőképp VIO szervereken.
A feladat: kideríteni, hogy:
- Mi dobta a core-t
- Miért dobta az a valami azt :)

Az első kérdésre alap esetben azt mondanám, hogy az errpt-ben nézzünk körbe, viszont most pont sikerült egy olyan helyzetbe bele fussak, ahol az errpt (más hibák miatt) már rotálódott, szóval más utat kell találni ennek kiderítésére. Sebaj, van 2 módszer is amit lehet használni:

1) - strings parancs: kicsit ügye fogyott, de azért még jól használható arra, hogy 1-2 környezeti adatot megismerjünk :)
server@root # strings /core | grep ^_=
 _=/opt/IBM/ITM/aix523/va/bin/kvaagent
 _=nY
 _=/usr/bin/grep
 _=/u
 _=/u
Ebből persze még nem lehet sok mindent levonni, de az a /opt/IBM/ITM/aix523/va/bin/kvaagent igen kecsegtetően néz ki.

2) - lquerypv: Az ember nem is gondolná mennyire de hasznos tud lenni ez a kis parancs, pedig meglehetősen sokoldalú, ha tudjuk mit és hol is keressünk :) Jelen esetben a 6E0 cím az ami minket foglalkoztat, ugyan is AIX alatt a core file-on belül mindig ezen a címen kell legyen az aktuális bináris neve, ami a core-t dobta:
server@root # lquerypv -h /core 6E0 16
 000006E0 61697844 61746150 726F7669 6465722D |aixDataProvider-|
 000006F0 36310000 00000000 00000000 00000000 |61..............|
aixDataProvider-61.. Ez persze nem sokat mond egy átlagos embernek, aki viszont dolgozott már ITM6 alatt VA agent-el az tudhatja, hogy ez az a process ami a kvaagent alatt fut szinte mindig, ergó jó nyomon járunk.

Nézzük a 2. kérdésre a választ.. Hogy került oda az a core.. Nos, ennek megállapításához több dolog is kell:
- Az aktuális bináris ami a core-t dobta (nem baj, azt az első lépésben már megtaláltuk, max a pontos helyét nem tudjuk még, de azt egy find se perc alatt megmondja :)
- DBX parancs azonos kernel és futtatókörnyezetben (Ez se gáz, max használjuk azt a gépet ahol az issue előjött :))
- Némi kis tudás, hogy mit is kéne nézni ...
- .. Illetve hogy hogy is kéne értelmezni..
Na haladjunk sorban, aztán meglássuk meddig jutunk..
- Na szóval, első pont: Az aktuális binárisunk.. Rövid find keresés, majd meg is találjuk a /opt/IBM/ITM/aix523/va/bin/aixDataProvider-61 alatt.
- Második pont: A dbx parancs a bos.adt.debug csomag része, ha nincs fent a gépen, akkor vagy feltesszük, vagy keresünk egy másik gépet ami megfelel a fenti kritériumoknak. Jelen esetben nekem épp fent volt a csomag :)
- Harmadik pont. Na itt jön a vicces rész. 1x is be kell hívjuk a core-t a dbx debuggerbe, majd meg kell néznünk hol is akadt el, aztán abból kitotózni, hogy mi volt a gond.
Kezdésként hívjuk be a dbx-et ay adott core file-ra:
server@root #  dbx /opt/IBM/ITM/aix523/va/bin/aixDataProvider-61 /core
 Type 'help' for help.
 warning: The core file is truncated. You may need to increase the ulimit
 for file and coredump, or free some space on the filesystem.
 [using memory image in /core]
 reading symbolic information ...warning: no source compiled with -g 
 
 Segmentation fault in . at 0x100286cc ($t1)
 0x100286cc (???) 7cc5212e stwx r6,r5,r4
Majd nézzük meg hol is hasaltunk el (where parancs):
(dbx) where
 get_diskstats() at 0x100286cc
 adp_get_diskstats(0x2ff21804) at 0x10005a88
 dt_CollectDiskData(0x3052a680, 0x30321748) at 0x1002d6a8
 dt_CollectData(0x3052a680, 0x30321748) at 0x10031b74
 itmTranslator(0x0) at 0x10032834
 main(0x1, 0x2ff21e40) at 0x1000619c
Na ez a legtöbb embernek nem mond semmit a kód ismerete nélkül (nyugi, az adminoknak se), viszont tökéletes kiinduló alap, hogy megnézzük, hogy ismert stack-ről van e szó (IBM jó szokása, hogy sokszor mellékelnek stack példát az ismert bugokhoz, így csak a stack ismeretével is el lehet indulni valamerre (Ha meg nem találunk semmit, akkor is rossz esetben a stack-el nyitni lehet egy PMR-t és hivatalos segítséget kérni).

Esetünkben mondhatni mázlink van: A 'get_diskstats adp_get_diskstats dt_CollectDiskData dt_CollectData itmTranslator site:ibm.com' google keresőszavak meglehetősen sok találatot adnak. A legjobb találat azt hiszem ez az oldal ahol 4 helyen is szinte azonos stack van (minimális eltérésekkel), így már csak arra kell rájöjjünk, hogy az oldalon említett IF0004 (version 6.2.2.2 FP4) valóban megoldja e a problémát. Ehhez persze nem árt tudni, hogy most épp milyen szinten van a progink :)

Erre ITM6 alatt 2 verzió van:
- Ha az UX agent is telepítve van, akkor /opt/IBM/ITM/aix526/ux/bin/itmver.sh script segítségével ki lehet kérni bármelyik agent verzió számát (sajna ez az én VIO-mon nem volt fent)
- A /opt/IBM/ITM/registry/ mappa alatt lévő file-ből ki lehet nézni a verziót direktben (grep a VRMF stringre) :)
server@root #  # grep VRMF /opt/IBM/ITM/registry/vaaix*.ver
 VRMF = 06220102
Jelen esetben ez a következőt jelenti: version 06.2.2.01.02 -> 6.2.2.1 FP02.

Bingó. /* Nem véletlenül standard policy az, hogy frissíts ha teheted, mert a hibák nagyja már esélyes, hogy javítva van */

2013. május 16., csütörtök

Corrupt system dump - Nem bírja a rendszer, szívjál még egyszer..

Sajnos az elmúlt időszakban inkább project jellegű munkákkal kellett foglalkozzak (ami inkább a tervezési munkálatokat fed le), mint sem tényleges rendszer üzemeltetéssel (ami meg az esetleges hibák debugolását), így el kellett telnie némi kis időnek, míg valami fincsi problémára rá tehettem a kezem.
Most viszont végre sikerült valami kellemesbe is belekóstolnom :)

A történet előzménye röviden a következő: Adott egy nem épp up-to-date AIX rendszer, ami hirtelen dobott egy hátast, plusz a hozzá járó kernel dumpot, és ki kéne deríteni, hogy pontosan mi a fene lehetett a háttérben (az applikáció eléggé nem szereti a magasabb AIX levelt, így mielőtt ráböföghetném, hogy "AIX-et kéne frissíteni wazze" még be kell bizonyítanom, hogy valóban az AIX volt e a ludas). Tekintve, hogy az ilyen jellegű vizsgálódások annyira nem állnak tőlem távol, így örömmel kezdtem neki a probléma megoldásának, bár az örömöm nem tartott sokáig..

Kezdésként nézzük a helyzetet:
# oslevel -s
5300-08-02-0822
// No igen.. Ennek a TL-nek a hivatalos supportja még 2010 Áprilisában járt le, ráadásul még 2010 Májusban kiadtak hozzá az SP10-et. Ez az SP még 2008ban jött ki, szóval gondolhatjátok, hogy milyen régi applikáció futhat rajta, ami miatt még az AIX-et se merik upgrade-elni..
# errpt | head -3
IDENTIFIER TIMESTAMP  T C RESOURCE_NAME  DESCRIPTION
67145A39   0325114513 U S SYSDUMP        SYSTEM DUMP
F48137AC   0325114213 U O minidump       COMPRESSED MINIMAL DUMP

Jó.. Szóval legalább az alapok meg vannak.. Nézzük, hogy mire számítsunk:
# errpt -aj 67145A39
---------------------------------------------------------------------------
LABEL:          DUMP_STATS
IDENTIFIER:     67145A39

Date/Time:       Mon Mar 25 11:45:00 NFT 2013
Sequence Number: 900224
Machine Id:      00CD98ED7C00
Node Id:         application_server
Class:           S
Type:            UNKN
Resource Name:   SYSDUMP         

Description
SYSTEM DUMP

Probable Causes
UNEXPECTED SYSTEM HALT

User Causes
SYSTEM DUMP REQUESTED BY USER

        Recommended Actions
        PERFORM PROBLEM DETERMINATION PROCEDURES

Failure Causes
UNEXPECTED SYSTEM HALT

        Recommended Actions
        PERFORM PROBLEM DETERMINATION PROCEDURES

Detail Data
DUMP DEVICE
/dev/dumplv
DUMP SIZE
            2147483136
TIME
Mon Mar 25 11:40:12 2013
DUMP TYPE (1 = PRIMARY, 2 = SECONDARY)
           2
DUMP STATUS
          -2
ERROR CODE
           0
DUMP INTEGRITY
This dump may be unusable - The alloc_kheap component is missing. 
This dump may be unusable - The alloc_other component is missing. 
This dump is incomplete - The end-of-dump component is missing. 

FILE NAME

PROCESSOR ID
           0
Tehát a rendszer váratlanul megállt, de a keletkezett dump nem teljes.. Innen indul a kihívás..

Tekintve, hogy van egy minidump-unk, így legalább abban reménykedhetünk, hogy abból ki tudunk valamit hámozni. Erre a legegyszerűbb az mdmprpt parancs.
# mdmprpt 
MINIDUMP VERSION 4D32
***************************************************
64-bit Kernel, 108 Entries

Last Error Log Entry: 
         Error ID: 9AA1914A      Resource Name: SYSVMM 
         Detail Data: 0000000042000000 00007FFFFFFFD080 
        F10001005DDD11F0 FFFFFFFFFFFFFFF3

This minidump is corrupted
Meg se lepődök.. Tekintve, hogy a dump-unk incomplete, így nem is vártam konzisztens dump-ot, bár a corrupt dump azt jelenti, hogy esélyünk nincs ezt az entry-t ellenőrizni. Egyedül annyi derül ki, hogy az utolsó jegyzett hiba a 9AA1914A error ID-ra mutat, ami a SYSVMM-hez köthető. Gyors segítség: VMM - Virtual Memory Manager, így innentől már sejthető, hogy itt valami memória művelethez köthető dolgon csúszott meg a rendszer. De azért nézzük meg, hogy a 9AA1914A error ID mit is takar a valóságban:
# grep -i 9AA1914A /usr/include/sys/errids.h
#define ERRID_DSI_MEMOVLY    0x9aa1914a /* A kernel memory overlay has been detected */
Memory overlay - teljesen fedi a VMM hatáskörét, úgy hogy eddig ez rendben is van.. Na de hogyan tovább? Ja igen.. Van még egy dumpunk. Ezt mentsük le a dump device-ról amíg lehet, aztán nézzük meg mit találunk benne:
# dd if=/dev/dumplv of=/dump_check/sysdump bs=4096 count=2147483136
// Itt megállnék egy pillanatra: Normális esetben a dump compression be van kapcsolva, ami azt jelenti, hogy a kiszedett dump-ot még ki is kéne tömöríteni a dmpuncompress paranccsal, jelen esetben viszont erre nem volt szükség, mivel a dump compression ezen a gépen nem volt bekapcsolva. Innentől lehet tippelni, hogy miért is nem fért el a dump, és hogy én ez miatt mennyire de boldog voltam.
# kdb /dump_check/sysdump
The specified kernel file is a 64-bit kernel
sysdump mapped from @ 700000000000000 to @ 70000007ffffe00
Preserving 1411195 bytes of symbol table
First symbol __mulh
Component Names:
 1)  minidump [2 entries]
 2)  dmp_minimal [9 entries]
 3)  dump_pad53 [1 entries]
 4)  proc [4101 entries]
 5)  thrd [7291 entries]
 6)  rasct [1 entries]
 7)  ldr [2 entries]
 8)  iplcb [1 entries]
 9)  errlg [3 entries]
10)  mtrc [98 entries]
11)  lfs [1 entries]
12)  bos [4 entries]
13)  ipc [7 entries]
Premature end of data in dump file.
Component Dump Table has 11523 entries
           START              END 
0000000000001000 0000000003E04050 start+000FD8
F00000002FF47600 F00000002FFDC940 __ublock+000000
000000002FF22FF4 000000002FF22FF8 environ+000000
000000002FF22FF8 000000002FF22FFC errno+000000
F100070F00000000 F100070F10000000 pvproc+000000
F100070F10000000 F100070F18000000 pvthread+000000
PFT:
PVT:
id....................0002
raddr.....0000000002000000 eaddr.....F200800090000000
size..............00080000 align.............00001000
valid..1 ros....0 fixlmb.1 seg....0 wimg...2
Unable to establish context with current thread
Unable to establish context with current thread
Unable to find kdb context
Dump analysis on CHRP_SMP_PCI POWER_PC POWER_6 machine with 32 available CPU(s)  (64-bit registers)
Processing symbol table...
.......................done
        ERROR: Unable to acess nfs_syms
(0)> where
Unable to establish context with current thread
Unable to establish context with current thread
[kdb_read_mem] no real storage @ F1000100100EE800
Unable to establish context with current thread
Unable to establish context with current thread
Unable to find kdb context
(0)> f
Unable to establish context with current thread
Unable to establish context with current thread
[kdb_read_mem] no real storage @ F1000100100EE800
Unable to establish context with current thread
Unable to establish context with current thread
Unable to find kdb context
(0)> stat
SYSTEM_CONFIGURATION:
CHRP_SMP_PCI POWER_PC POWER_6 machine with 32 available CPU(s)  (64-bit registers)

SYSTEM STATUS:
sysname... AIX
nodename.. application_server
release... 3
version... 5
build date May 12 2008
build time 23:42:11
label..... 0820A_53N
machine... 00CD98ED7C00
nid....... CD98ED7C
time of crash: Mon Mar 25 11:39:02 2013
age of system: 124 day, 7 hr., 56 min., 32 sec.
xmalloc debug: enabled
Debug kernel error message: A program has tried to store to freed or redzoned xmalloc memory.
Address at fault was 0xF10001005DDD11F0
Na akkor röviden: Az alap parancsok mind elhullanak azon oknál fogva, mert a dump-unk nem teljes, amúgy meg annyit tudunk meg mint előzőleg - memória kezelési gubancok vannak a háttérben.

Egy dolog viszont ott van amit talán lehet használni: a CDT adatok (component-dump tables), amit a kdb az elején jelzett is. Ami nekünk kelhet az jelen esetben a minidump, vagy az errlg tábla, tekintve, hogy ezek még talán tartalmazhatnak valami kis támpontot, hogy merre tovább.

Első körben én a minidump-ra koncentráltam:
(0)> cdt 1
Dump table entries in CDT:

CDT ENTRY VMHANDLE       ALIAS        ADDRESS LENGTH   NAME
  1     1 kernel             0000000002B1AA50 00000046 md head
  1     2 kernel             0000000002F1E9FC 00000E60 minidump
Tekintve, hogy a dump is tartalmazza a minidump-ot, így első körben az volt a tervem, hogy azt fogom kiszedni onnan, majd használható állapotba hozni, viszont egy részről ez -mint utólag kiderült- nem volt kivitelezhető (az okokat most nem tárgyalom), így más útvonalon kellett elinduljak
// Az minidump-al való mókolást szerintem majd egy külön blogban tárgyalom ha lesz rá érdeklődés

Mázlimra az AIX-nek van 1-2 beépített parancsa bizonyos típusú adatok kinyerésére a dump file-okból, csak ezeket valamiért a dokumentációk nem nagyon emlegetik. Az egyik ilyen parancs a dmp_minimal (ami még véletlenül sincs dokumentálva), a másik pedig az errdead (ami még úgy ahogy dokumentált).
Előző célja, hogy az elérhető minidump-ot kinyerje a dump file-ból, és megpróbálja azt értelmezni, utóbbi pedig a boot során keletkezett error logok kinyerésére használható a dump file-ból.
#  /usr/lib/ras/dmprtns/dmp_minimal /dump_check/sysdump|tail -15
traceback:
 iar:0000b920 unknown
  lr:002f7eac slock+148
addr:002f806c slock+308
addr:000090c4 unknown
addr:044901f8 store_packet+70
addr:04490880 pcd_output[DS]+98
addr:044473f8 en_output+1218
addr:0430974c ip_output_post_fw+1f50
addr:04309b04 ip_output+100
addr:0433bb44 tcp_output+2404
addr:0436d2a0 tcp_usrreq+17a8
addr:00223760 sosend+c88
addr:0023b2b8 send+4e0
addr:00003814 unknown
Na, legalább van egy stack-ünk. Megerősítésként azért nem árt átnézni az error logot is. Ehhez simán extractoljuk ki az error logot a dump-ból, majd adjuk oda az errpt-nek:
# /usr/lib/errdead -i ./errpt_out /dump_check/sysdump 
# errpt -i errpt_out
IDENTIFIER TIMESTAMP  T C RESOURCE_NAME  DESCRIPTION
9AA1914A   0325113913 P S SYSVMM         INVALID MEMORY REFERENCE
77EED6D9   0325113913 U S SYSALLOC       Deferred-free or redzoned memory read
Hoppá. Emlékszik még valaki a 9AA1914A-es hibakódra? Igen, ez az amire az mdmprpt is panaszkodott. Legalább ez az infó is megvan akkor. Sajna azonban a 9AA1914A-es error logban nem sok használható infó van, viszont annál több a 77EED6D9-esben:
# errpt -i errpt_out -aj 77EED6D9
---------------------------------------------------------------------------
LABEL:          XM_READ_FREE
IDENTIFIER:     77EED6D9

Date/Time:       Mon Mar 25 11:39:02 NFT 2013
Sequence Number: 1
Machine Id:      00CD98ED7C00
Node Id:         application_server
Class:           S
Type:            UNKN
Resource Name:   SYSALLOC        

Description
Deferred-free or redzoned memory read

Probable Causes
LOADABLE SOFTWARE MODULE
SOFTWARE DEVICE DRIVER
OPERATING SYSTEM

Failure Causes
MEMORY ALLOCATION ERROR

        Recommended Actions
        PERFORM PROBLEM DETERMINATION PROCEDURES
        CONTACT YOUR LOCAL IBM SERVICE REPRESENTATIVE

Detail Data
Stack Trace
slock+11C
slock+304
[90C0]
store_packet+6C
pcd_output[DS]+94
en_output+1214
ip_output_post_fw+1F4C
ip_output+FC
tcp_output+2400
tcp_usrreq+17A4
sosend+C84
send+4DC
[3810]
-errSTKfrm-
Mint látható, a 2 parancs által szerzett stack kb azonos (annyi különbséggel, hogy az errpt az ismeretlen hívások helyére valami -nekünk irreleváns- címet illesztett be), így nyugodtak lehetünk, hogy jó nyomon járunk.

Jó, de innen hova tovább? Azt nem tudjuk megnézni, hogy a regiszterekben milyen adat volt, a forráskódhoz nem férünk hozzá, hogy tudjuk minek és hol is kéne pontosan lennie, csupán egy stack állapotunk van. Ez miatt általában azt szoktam mondani, hogy tessék utána járni, hogy van e olyan APAR, ami hasonló, vagy (ami még jobb) azonos stack-et produkál e, ugyan is ekkor szinte biztosak lehetünk, hogy abba a bug-ba sikerült belebotlanunk, de még hasonlót se találtam ami ilyesmi stack-et írt volna le (a 2 unknown hívás meg pláne nem segít semmit).

Na innentől általában egyenes út a software call felé, de szinte biztos, hogy ilyen dump-al ők se tudnak sokat kezdeni, plusz mivel enyhén outdated AIX level-t futtatunk, így csuklóból közölnék, hogy ez a verzió nem támogatott, illetve ajánlatos lenne azonnal update-elni, mivel azóta már jó pár javítás kijött, és hátha valamelyik erre is megoldást nyújtana.

// Itt akár be is fejezhetném ezt a blog bejegyzést, ugyan is technikailag már sok újdonságot nem fogok leírni, viszont akit érdekel a teljes történet, annak azért leírom, hogy hogy is folytatódik ez a kis történet.

Na szóval. A probléma ezzel a felállással innentől az, hogy az ember 2 szék között a pad alá kerül rövid úton, úgy hogy ez így nem játszható.
Van azonban még 1 kis aranyágacska, amin el lehet indulni: A stackben látható pcd_output hívás nem része a standard AIX hívásoknak, így kis kutakodás után sikerült kideríteni, hogy azt egy extended kernel module biztosítja, ami az IBM RealSecure Server-hez (aka ISS) tartozik, ami akkor szintúgy bekavarhat, úgy hogy ennek a szálnak is utána kell járni.

// Megjegyzés: az ISS egy extra védelmi réteget húz a hálózati kommunikáció elé, és monitorozza a hálózati forgalmat. Ha valami gyanúsat észlel, akkor azt elvileg képes megfogni, így biztosítva némi IDS funkcionalitást. Az outdated AIX verzióra való tekintettel ennek jelenléte még teljesen érthető is..

Első körben a kérdés az, hogy milyen modul biztosítja azt a hívást.. 2 lehetőség van ennek kiderítésére: Vagy rátámaszkodunk a naming convention-re, és azt mondjuk, hogy a pcd_output hívás valószínű valami pcd szerű driver hozza, vagy megnézzük, hogy az ISS csomagban van e, és ha igen, akkor milyen driverek vannak a csomagon belül.
# lslpp -l |grep ISS
  ISSXss.ServerSensor        7.0.0.0  COMMITTED  IBM RealSecure ServerSensor
  ISSXss.ServerSensor        7.0.0.0  COMMITTED  IBM RealSecure ServerSensor
  
# lslpp -f ISSXss.ServerSensor |grep driver
/usr/lib/drivers/
/usr/lib/drivers/pcd.ext
Na.. Így már biztosabbak lehetünk a dolgunkban. Következő kérdés, hogy a modul valóban be volt e töltve a dump pillanatában.. Irány vissza a kdb-be, majd listázzuk ki a betöltött modulokat, és szűrjünk arra amit találtunk:
(0)> lle -k |grep pcd.ext
  9 03EDDB00 0448C000 00016150 00080252 /usr/lib/drivers/pcd.ext
Bingo.. Tehát be volt töltve. Innentől akkor már csak az a kérdés, hogy ez okozta e a hibát, avagy az AIX. 100%-ra pontosan persze nem tudjuk megmondani, de azt azért érdemes megnézni, hogy az ISS-ünk is outdated-e.

Na itt kezdődött a következő problémám.. A hivatalos IBM javítások között a legfrissebb verzió a 7.0.42.2, a rendszeren viszont semmiféle utalás nincs a pontos verzióra nézve, csupán a csomag 7.0.0.0-ás verziószáma, ami viszont véletlenül se használható támpont.
A végleges megoldás végül az lett, hogy leszedtem a javítást az IBM FixCentral oldaláról, kicsomagoltam a base64 encode-olt telepítőt (így kaptam egy BFF csomagot), abból kibontottam a tényleges file-okat, és összehasonlítottam a checksum értékeket a rendszeren lévőkkel: Egyeztek -> Tehát ebből a programból legalább a legfrissebb verzió volt telepítve a gépre.

// Ez úton is üzenném minden programozónak, hogy valami nyamvadt verziózást rakjatok már bele a programotokba, különben lehetetlen lesz lekövetni, hogy épp mikor kell frissíteni az adott szoftvert.

Tehát a felállás innentől a következő: Van egy program, aminek a kernel module-ja szinte biztos, hogy szerepet kapott a hibában, viszont az a jelenlegi legfrissebb verzió, ergo vagy sikerült egy olyan bugba belebotlani, amire még vagy nincs javítás, vagy még nem is ismert, vagy tényleg az AIX outdated státusza okozta a galibát, és kompatibilitási hibával állunk szemben. Utóbbit sajna biztosra meg nem lehet mondani, mivel a hivatalos dokumentum véletlenül se taglalja, hogy van e TL/SP függősége, így nem maradt más hátra, mint közölni a customerrel, hogy nagy eséllyel tényleg frissíteni kéne az AIX-et (Minimum felrakni a legutolsó Service packot ehhez a TL-hez; azt az applikáció nagyobb eséllyel éli túl, mint mondjuk egy TL upgrade-et), bekapcsolni a dump compression-t, és ha az után is előjön a probléma, akkor újabb SW call-t nyitni. Ha ez nem kivitelezhető, akkor sorry, de ez egy olyan known risk amivel együtt kell majd élnie.

2013. január 29., kedd

Mickey egér, HACMP, meg a többiek..

Némileg úgy érzem most magam, mint ahogy régen a BBC stábja érezhette magát, amikor is 1946ban (állítólag, bár egyesek szerint ez is kacsa) ismét ott folytatták az ominózus Mickey Mouse történetet, ahol anno 1939 Szeptember 1.-jén abbahagyták.

Ok, némileg túlzó a kép, de azért nekem is volt 1-2 komolyabb harcom az elmúlt 1-2 hónapban, munkahely váltás, költözés külföldre, meg ami vele jár.. Szóval nem volt eseménytelen az elmúlt időszak, ami sajna a blog rovására is ment láthatólag.
Na de viszont most megpróbálom azt amit anno a BBC-sek is - folytatni ahol abbamaradt minden, mintha misem történt volna..

Na szóval.. Aktuális problémánk tárgya egy HACMP-s node, ahol a clcomdES daemon fölött elkezdtek körözni a keselyűk, ugyan is ránézésre halottnak nézett ki..
Az AIX kommandó az újraélesztést megkezdte, de a beteg nem reagált a kezelésre:
[server:root:/home/root:] lssrc -s clcomdES
Subsystem         Group            PID          Status 
 clcomdES         clcomdES                      inoperative
[server:root:/home/root:] startsrc -s clcomdES
0513-059 The clcomdES Subsystem has been started. Subsystem PID is 7033284.
[server:root:/home/root:] 
[server:root:/home/root:] lssrc -s clcomdES   
Subsystem         Group            PID          Status 
 clcomdES         clcomdES                      inoperative
Az orvosi lapot átnézve kiderült, hogy betegünk valószínű még is él, csak vagy kómába esett, vagy önmagán kívül van:
[server:root:/:] tail -1 /var/hacmp/clcomd/clcomd.log 
Mon Jan 28 15:03:18 2013: bind (../../../../../../../src/43haes/usr/sbin/cluster/clcomd/clcomd.c:5533): Address already in use
Persze minderről a hatóságok semmit nem tudtak..
[server:root:/var/hacmp/clcomd:] ps -ef |grep clcom 
    root 5480538 7143926   0 15:05:31  pts/1  0:00 grep clcom 
.. csak annyit, hogy a clcomdES által gyakran használt erőforrásokat valami tényleg épp fogja:
# Kis magyarázat: a clcomdES által használt default port a 6191
[server:root:/var/hacmp/clcomd:] netstat -Aan |grep 6191 |grep LISTEN
f10006000243c398 tcp4       0      0  *.6191             *.*                LISTEN
Ilyenkor általában csak odasétál az ember az illetékes besúgóhoz, megkéri hogy mondja már meg ki jár rá a dugi csokira, de szomorúan kell konstatáljuk, hogy halvány lila fogalma nincs:
[server:root:/var/hacmp/clcomd:] rmsock f10006000243c398 tcpcb
getprocdata: malloc failed
Na jó... Ha a szokványos eszközök nem mennek, akkor tényleg muszáj lesz nekünk is bemocskolnunk a kezünk, és megnézni hogy a Disc-réten mi ROMolhatott el..

Kezdjük is a kernellel, ha már a gyanúsítgatásnál tartunk ("Ahol a kormány, ott van a gáz.."). Aki olvasta eddig a blogomat annak ez a fordulat azt hiszem nem lesz komolyabb meglepetés :)
Akinek még is, annak javaslom az itt emlegetett módszerek és parancsok áttanulmányozását a folytatás előtt

Na szóval.. a netstat megsúgta nekünk, hogy a f10006000243c398-es dugi csokira jár rá a kis szellemünk, úgy hogy kezdjünk el az után nyomozni első körben:
[server:root:/var/hacmp/clcomd:] kdb
(0)> ns
Symbolic name translation off
(0)> si f10006000243c398 tcpcb |grep ACTIVE
F100070F01012000 16456*clcomd   ACTIVE 004812E 0031166 00000003184E1400   0 0014

(0)> proc F100070F01012000 |head
              SLOT NAME     STATE      PID    PPID          ADSPACE  CL #THS

F100070F01012000 16456 clcomd   ACTIVE 004812E 0031166 00000003184E1400   0 0014
Hoppá.. Tehát a socketet még is csak egy clcomd fogja, de akkor miért nem vették észre a nyomozó kollégák??
(0)> hcal 004812E
Value hexa: 0004812E          Value decimal: 295214

[server:root:/:] ps -fp 295214
     UID     PID    PPID   C    STIME    TTY  TIME CMD
       -  295214       -   -                     - <exiting>
Ja kérem.. Ez itt egy megrendezett öngyilkossággal egybekötött biztosítási csalás.. Na keressük meg a cinkosokat:
(0)> proc F100070F01012000 |grep THREAD
THREAD..... threadlist :F100070F10807300 
THREAD..... threadcount:00000014  ........... active     :00000002

(0)> th F100070F10807300 |head
                SLOT NAME     STATE    TID PRI   RQ CPUID  CL  WCHAN

F100070F10807300 32883  ZOMB  0731E3 03C    0         0  

NAME................ 
WTYPE............... WZOMB    
.................tid :00000000000731E3  ......tsleep :FFFFFFFFFFFFFFFF
...............flags :00000000  ..............flags2 :00000000
...........pmcontext :00000000
DATA.........pvprocp :F100070F01012000 
Hoppá.. Nekromancia, vagy mifene? Ki mozgatja a szálakat?
(0)> th F100070F10807300 |grep prev 
LINKS.....prevthread :F100070F10008C00 
LINKS.....prevthread :0000000000000000

(0)> th F100070F10008C00 |head
F100070F10008C00  140 clcomd   SLEEP 08C029 03C    4         0  F100070F010121B8 
Jó.. 1 megvan.. Vannak még?
(0)> th -n clcomd
                SLOT NAME     STATE    TID PRI   RQ CPUID  CL  WCHAN

F100070F10007C00  124 clcomd   SLEEP 07C0ED 03C    4         0  F1000110129D9A70 01125380 
F100070F10008C00  140 clcomd   SLEEP 08C029 03C    4         0  F100070F010121B8 
Aham.. szóval 2 fő process, 1-1 threaddel.. Na és ők épp mit csinálnak?
(0)> f F100070F10008C00
pvthread+008C00 STACK:
[0005EEF4]ep_sleep+000128 (0000000000056DA0, A0000000000090B2 [??])
[0014384C]kexitx+000F6C (??)
[0015AAD8]kexit+000080 ()
[kdb_get_virtual_memory] no real storage @ FFFFFFFF3FFFE40

(0)> f F100070F10007C00
pvthread+007C00 STACK:
[002FF8C0]slock+0006A4 (00000000002E0268, 80000000000090B2 [??])
[00009558].simple_lock+000058 ()
[002CB3D0]j2_rename+000188 (??, ??, ??, ??, ??, ??, ??)
[00408C34]vnop_rename+0002B4 (??, ??, ??, ??, ??, ??, ??)
[0046A8F4]rename+00030C (??, ??)
[0486570C]my_rename+0001C4 (0000000020023728, 00000000200C149C)
[00003810].svc_instr+000110 ()
[kdb_get_virtual_memory] no real storage @ 200C0FD8
[10013190]log_printf+0002FC (00000000, 00000000, 00000000, 00000000,
   00000000, 00000000, 00000000, 00000000)
Az egyik épp ki akar lépni, de azért még vár egy kicsit (tapsra talán, meg nem mondom), de a másik már érdekesebb: Ott a jelek szerint épp valami JFS2-es FS alatt volt valami átnevezősdi, ami valahogy még is csak megbicsaklott..
És hiába tűnt ez az elején HACMP hibának, a bizonyítékok alapján ez inkább tűnik AIX issue-nak.. A pénz csak pénz, a stack az meg csak stack na..
Azok alapján meg az ügy erősen hajaz az alábbi hibák egyikére:
- IZ96928
- IZ40258
Na most ha megnézitek, akkor azért ezek a bűnügyi megelőző kezelések nem épp a legfrissebben szabadult bűnözőkre lettek kitalálva (avagy jó régi patchekről van szó).. Úgy hogy ha már itt tartunk nézzük már meg, hogy ezt a drágát melyik korból szalajthatták?
[server:root:/:] oslevel -s
5300-08-08-0943
Jah.. Jó.. Ez a TL/SP még anno 2009 Novemberében lett kiadva.. Az se ma volt.. Had ne mondjam azóta mennyi fix kijött, jah meg az 5.3as AIX hivatalos supportja is lejárt 2012 Áprilisában.
Na szóval itt rendesen el vannak egyesek maradva.. És hiába kérdezik meg az SWG-sek (software group) hogy tuti minden patch fent van e, attól még a hülye AIX admin csak abból főzhet amit a konyhában talál (amíg ki nem derül, hogy a Műanyag tálba lévő melegítendő kaját lehet még sem a sütőn kellett volna megpróbálni felmelegíteni).

Tanulság: Ha tetszik, ha nem tessék már azokat a rohadt rendszereket frissíteni (és nem csak a security miatt)

2012. május 28., hétfő

Sudo te drága.. De sokat kell érted fizetni időnként :)

A sudo nevű utility-t szerintem nem kell senkinek se bemutatnom.
Segítségével (minimum féldisznóért) root hozzáférést kaphatunk kedvenc adminisztrátorunktól az adott (természetesen teszt) rendszerünkhöz (NOPASSWD-s rule-al, mert jelszót beírni senki nem szeret :)), így szabadon garázdálkodhatunk és nézelődhetünk, hogy ha valami gáz van a kódban (avagy "De hisz ez még tegnap működött!").
Persze azt se szabad elfelejteni, hogy ezen eszköz révén némileg le tudjuk korlátozni az olyan usereket is, akiknek helyenként root jogosultság kéne, hogy elindítsanak valamit ("Hogy hogy nem képes a WAS support team elindítani a 80as portra bindelő WAS-t root hozzáférés nélkül? Felháborító!")

Lényeg ami lényeg: AIX/Linux alatt ez a progi több mint kötelező, hacsak némileg is törődünk a gép biztonságával. Persze ennek telepítése után se lesz kolbászból a kerítés, sőt, még plusz melót is vartunk a nyakunkba azzal, hogy a /etc/sudoers-t karban kell tartani, de hát istenem, ki mondta, hogy a security fenékig tejföl?

Az issue amivel jelen esetben sikerült szembetalálkoznom kb úgy kezdődött mint minden szokásos "ÚR ISTEN, SECURITY HOLE!!!!" jellegű felkiáltás:
Az IBM által hivatalosan elérhetővé tett sudo 1.6.9p23-as szinten van, viszont pár napja felütötte a fejét egy olyan hiba, ami ezt a verziót is érinti, a customer meg persze az ilyeneket olvasva sikoltozva kiabálja, hogy azonnal tedd fel a javítást. A probléma persze csak az, hogy a hivatalos IBM-es csomag nem elérhető, ergo hivatalos javítást nem tudsz feltenni, ha akarsz se. Customer-t ez persze nem hatja meg, a sudo amúgy sem IBM product, forgass egyet magadtól, az annyira amúgy se nehéz..

Így is lett. Az ember forgat magának 1.7.9es csomagot (hivatalos IBM support innentől sudo-t ne akarjon supportolni :)), customer örül, And so once again the day is saved. Murphy persze hogy erre az alkalomra vár és bedobja az "I don't think so" kártyáját, aztán az admin már meg se lepődik, amikor a customer ismét telefonál, hogy "Őőő.. ez most miért nem megy"? *sigh*

A történet kb az alábbi: Az 1.7.9es sudo óta bejött AIX alatt egy regresszió az alábbi change miatt:
- If none of the standard input, output or error are connected to a tty device, sudo will now check its parent's standard input, output or error for the tty name on systems with /proc and BSD systems that support the KERN_PROC_PID sysctl. This allows tty-based tickets to work properly even when, e.g. standard input, output and error are redirected to /dev/null.

Ez AIX alatt kb úgy néz ki, hogy amennyiben nincs tty device-od a sudo hívásakkor, úgy pityiszt kapsz az orrodra, nemhogy lefutott parancsot.. Persze az ember valami hibaüzenet féleséget várna minimum, de a sudo-val meghívott process ez helyett szimplán csak hang-el, és nem csinál semmit.. Ez persze kifejezetten kellemetlen amikor a customer által futtatott rendszer egy DB2 osztott cluster, ami rah parancsokat használva szeretne a node-okkal kommunikálni, ami persze hogy tty nélküli kulcs alapú ssh chanelleket használ(na), így nem csoda ha a rah parancs is beáll, mint a gerely.

Mondanom se kell, hogy az ember ilyenkor mennyire fel van dobva, és már a telefonálás pillanatában elönti az adrenalin, és a tettvágy, hogy egy ilyen kaliberű hibát kinyomozzon anélkül hogy tudná mit és hol keressen :)
Röviden: pár óra kellemes orális szerelmeskedés (értsd: szopás) után megvan, hogy valószínű az új sudo a hibás, visszarakod a régit, és láss csodát, minden megy ahogy kéne..
Csak a rendszered lett megint non-compliant, tehát amit nyertél a réven, azt veszted a vámon, mert valahogy csak meg kell nézni, hogy mi a fene okozza ezt a hibát..

Újabb kellemes órák, újabb kellemes tesztelgetés, sudo.c turkálás, és hasonló jóságok után az ember eljut oda, hogy a hiba tényleg az 1.7.9ben jött be ( 1.7.8p1en még minden szépen megy), és ha a tty kezelési részt kicsit visszapiszkálja, akkor megy is minden szépen:
devel_box@root:/ # diff /tmp/sudo-src/sudo-1.7.9.gabor/sudo.c /tmp/sudo-src/sudo-1.7.9/sudo.c
628,631c628,630
<
<     if ((p = ttyname(STDIN_FILENO)) || (p = ttyname(STDOUT_FILENO)) ||
<         (p = ttyname(STDERR_FILENO))) {
<         user_tty = user_ttypath = estrdup(p);
---
>
>     if ((p = get_process_ttyname()) != NULL) {
>       user_tty = user_ttypath = p;
Oks.. akkor most már bizonyított: software bug.. nyissunk rá ticketet, aztán a fejlesztő majd megszakérti mi is a probléma -> Bug #557 a sudo-s bugtrackerben, megidézlek!

S lőn fél napon belül megvilágosodás: Valóban regressziót találtunk, sőt régebben már más is jelentette ezt a problémát, csak nem az 1.7-es, hanem az 1.8as szériához. Külön öröm, hogy a következő 1.7.10es verzióban már ez is javítva lesz, sőt, már a béta el is érhető, úgy hogy akinek ilyen igényei vannak, az használhatja azt..

A customer meg döntse el, hogy mit és hogy is akar ezek után :) Aki meg hasonlóval szív, az tegye vissza a régit, vagy használjon béta release-t, amíg az új ki nem jön :)

2012. május 6., vasárnap

Murphy és a "jó" design

Elég mozgalmas volt ez az április, így nem sok időm volt blogolni bármiről is, de azért egy "emlékezetes" issue úgy érzem megérdemel annyit, hogy megmaradjon az utókornak.

Hol volt, hol nem volt (az óperenciás rendszeren is túl) volt egy szerver, aminek a design-ját okos emberek kialakították, és megítélendék jónak. Persze az okos emberek teljesen másra szánták a gépet mint amire azt később a customer nevű állatfaj elképzelte. Így alakulnak ki a természetben az olyan félvér állatfajok, amik inkább csak a hibáikkal tűnnek ki, mint sem a használhatóságukkal, és tuti biztos, hogy a lelkes adminisztrátorok előbb utóbb rájönnek, hogy az ilyen szerverek is inkább csak elrettentő példának jók, min tsem produktív dolgok futtatására, de hát a customert ez a legkisebb mértékben se szokta érdekelni, neki csak az a fontos, hogy az über-fontos dolgok menjenek a gépen..

Na most.. Ha még vannak olvasók akik nálam jobb emlékezettel vannak megáldva, akkor nekik lehet dereng valami a múltból, amikor a design hibákat ecsetelgettem, és már akkor is elmondtam, hogy az adott architect-nek jó rejszolást kívánok egy sajtreszelő társaságában, hogy ezt a design-t képes volt megálmodni

Hogy, hogy nem, most Áprilisban jött el az ideje annak, hogy Murphy ismét szórakozni akarjon, és kitalálta, hogy ez az igen fontos gép amúgy is billeg a szakadék szélén, hát miért ne lökjön rajta egy kicsit.. Persze ha már ott van, akkor a mentőalakulatok útjába is felállít 1-2 csapdát, mert az úgy még is csak nagyobb a FUN faktor.

A valóságban mindez a következőképp realizálódott:
Első körben a fenti design-ban szereplő RAID 5 tömb alól 2 diszk úgy gondolta, hogy őt már nem becsülik meg eléggé, így Seppuku-t hajt végre. "Mázlira" csak az Egyik diszk volt aktív, a másik csak Hotspare, így elméletben még itt nem kéne nagy problémának lennie. Így hát új diszk beszerez, hotplug manager elő, aztán cseréljük on-the-fly a temetőbe szánt Hotplug diszket, ahogy az a nagykönyvben is meg van írva.

Sajna azonban a Nagykönyvekkel mindig az a baj, hogy az emberek elfogadják a benne leírtakat egyfajta axiómának, ami -ha Murphy is a képben van- általában nem teljesen szokta lefedni a valóságot: Így hát persze így se minden úgy működött ahogy kellett volna.. Történt ugyan is, hogy a teljesen szabályosan kicserélt új diszket a rendszer nem volt képes lekezelni, mivel a régi konnekciós azonosítót valamiért nem akarta felszámolni.
Hogy szemléletesebb legyen a dolog, kb ezt látja a szerencsétlen adminisztrátor:
# sissasraidmgr -L -j1 -l sissas5
------------------------------------------------------------------------
Name      Resource  State       Description              Size                  
------------------------------------------------------------------------
sissas5   FFFFFFFF  Primary     PCI-X266 Ext Tri-x4 3Gb SAS RAID Adapter
 sissas6  00000000  AWC linked  Redundant cache protection for sissas5  

hdisk3    00FF0000  Degraded    RAID 5 Array            1135GB                 
 pdisk0   00000200  Failed      Array Member           283.8GB                 
 pdisk1   00000300  Active      Array Member           283.8GB                 
 pdisk3   00000500  Active      Array Member           283.8GB                 
 pdisk2   00000400  Active      Array Member           283.8GB                 
 pdisk4   00000600  Active      Array Member           283.8GB                 

*unknwn*  00000700  RWProtected Array Candidate            N/A                 
pdisk5    00000700  Missing     Disk                   283.8GB
Na szóval.. Vagy egy hdisk3 néven létező RAID 5 tömbünk, ami épp Degrad állapotban leledzik, mindez a sissas5 adapteren. Van 2 halott diszkünk (pdisk0,pdisk5), ami közül pdisk5-öt igyekszünk épp kicserélni, ami jelenleg épp Missing státuszban leledzik. A pdisk5 kapcsolati címén (00000700) azonban van még egy diszk, ami épp RWProtected, amúgy meg unknown (tehát a rendszer nem tud róla semmit). Így meg persze még neki se lehet állni új Hotspare-t definiálni (hogy aztán azt majd bedobjuk a pdisk0 helyére)

Na ez az a rész, amiről a nagykönyv nem ír semmit (Murphy viszont a Pop-corn egy részét már elfogyasztotta).. Ergo akkor nincs más, csak kidobni a vak hitet, és menni az ember saját feje után.
Első körben az előzőleg kicserélt diszk-et kivéve a slotból lehetőség nyílt az unknown device "elvesztésére" ám a rendszer pofátlan módon ragaszkodott a pdisk5 jelenlétéhez, attól függetlenül, hogy az már közel, s távol nem volt a gépben. Külön poénként ezt a meggyőződését még akkor se volt hajlandó elfelejteni amikor a pdisk5-öt 'rmdev -dl'-el lelőttem, majd a config managert (cfgmgr) futtattam, mivelhogy az rendkívül ragaszkodóan visszahozta a pdisk5-öt "Available" státuszban (a RAID vezérlő persze még mindig Missing-nek látta).

Na akkor itt álljunk meg egy picit.. Felmerül a kérdés -gondolom- az olvasóban, hogy biztosan a jó diszk lett kihúzva? Igen, ez volt az első felmerülő kérdés bennem is, de többszöri vizsgálat után is csak az jött ki, hogy valóban a jó diszket piszkálom és az AIX (VIO, de a lényegen semmit nem változtat) az aki foggal körömmel ragaszkodik ahhoz a diszkhez.

Fejvakarás, cseresznyefák, és wattafák.. Avagy csak fák.. Kinek mi esik jól.. Murphy közben a Pop-corn mellett már elindította a háttérben a Kokaku Kidotai (Ghost in the Shell) OST-t is, mert ehhez a jelenethez ez illik a legjobban..

Adminisztrátor részről persze teljes értetlenség, keresés, látott e már valaki valami ilyesmit? Aztán szembejön ez a bug, és fény gyúlik a katakombákban : IZ72353 - SAS PDISK DISPLAYED AS *UNKNWN* AFTER REPLACE/REBUILD APPLIES TO AIX 6100-03

Jah hogy úgy... Hát úgy.. A gáz csak annyi, hogy a patch magában nem elérhető (mivel VIO-ról beszélünk, így csak VIO frissítéssel együtt oldható meg a csótányirtás), így (mivel már mindenki a hátunk mögött van, és a messzeségben már a mesterlövészek is a mi monitorunkat lesik a fejünk mellett) a leggyorsabb megoldás a restart marad. Persze előtte minden kliens azonnal állj, addig a VIO se mozduljon semerre..

Restart, öröm és boduttá.. A pdisk5 végre defined-ban jön fel, sőt az újonnan beletett vinyót is már látja a rendszer.. Sínen vagyunk mint József Attila..
HotPlug diszk megformáz 528 Byte Szektor mérettel, majd a pdisk0 kipöccintése után nyomban be is áll a helyére az immár hamvaiból feltámadt pdisk5 Főnix madár, indulhat az Array Rebuild, semmi ok a pánikra, minden a Ctrl billentyű alatt van

Hátradőlünk, és szépen várjuk, hogy a tömb újjáépítése befejeződjön. A háttérben viszont Murphy ráadást követel, így hát újabb szám zendül fel a hangszórókból.

A moziban ilyenkor kezdenének el villogni a piros villogók, felharsognának a szirénák, és valami kis rangú emberke kétségbe esve megszólalna, hogy "Sir, Something is wrong!" (Thank you, Caption obvious). A valóságban azonban az embert csak egy ilyen hibaüzenet fogadja a fekete putty ablak mögött:
# sissasraidmgr -L -j1 -l sissas5
------------------------------------------------------------------------
Name      Resource  State       Description              Size                  
------------------------------------------------------------------------
sissas5   FFFFFFFF  Primary     PCI-X266 Ext Tri-x4 3Gb SAS RAID Adapter
 sissas6  00000000  AWC linked  Redundant cache protection for sissas5  

hdisk3    00FF0000  Failed      RAID 5 Array            1135GB Rebuild Failed 04
 pdisk5   00000700  Failed      Array Member           283.8GB                 
 pdisk4   00000600  RWProtected Array Member           283.8GB                 
 pdisk3   00000500  RWProtected Array Member           283.8GB                 
 pdisk2   00000400  RWProtected Array Member           283.8GB                 
 pdisk1   00000300  Failed      Array Member           283.8GB                 

pdisk0    00000200  RWProtected Array Candidate        283.8GB

Őőő.. 'nyádat... Újratervezés..
- A pdisk5 most lett kicserélve, leformázva, leellenőrizve, így az garantáltan nem lehet halott (hacsak nem a vezérlő halt meg, de akkor már az ima is édeskevés lesz)
- A pdisk1re eddig nem jött egy hibajelentés se, így azt vessük górcső alá.
- Az errpt entry-jeit elnézegetve (54E8A127 error code (DEVICE OR MEDIA ERROR), ha valakit érdekel) az összes hibajegy a pdisk1-el megegyező Serial ID-ra jön, így tételezzük fel, hogy a pdisk5 Failed státusza az újraépítés során tapasztalt pdisk1 hibájának mellékhatása csak.

Ezzel viszont egy újabb probléma üti fel a fejét: A RAID5 tömb egyszerre csak 1 aktív diszk halált bír ki, kettőt már nem. Amennyiben a pdisk1-et is ki kell cserélni, akkor kalap,kabát, búcsút lehet mondani az adatainknak, mert 3 diszkből már nem engedi a vezérlő se helyreállítani a tömböt (Én megpróbáltam, de hát ez nem linux).
Egy mázli volt - amennyiben az ember újraindítja ebben a fázisban a VIO-t, akkor a SAS RAID vezérlő újra megpróbálja a tömböt össze-eszkábálni, ami viszont kitűnő alkalmat teremt arra, hogy az ember megpróbálja menteni ami menthető.

És itt most álljunk meg ismét egy pillanatra.
- Adott egy fél lábbal már a sírban lévő RAID5 tömb
- A tömbön lévő adatok egy része már garantáltan nem elérhető, tehát a disaster recovery elkerülhetetlen (ugye van disaster recovery plan? :) Megsúgom, az ilyen rendszereknél rendszerint nincs.. Itt a remek alkalom, hogy most fejben összeüss egyet, és imádkozz, hogy az a minimális backup process ami eddig volt elégséges legyen :D )
- Ha mindenképpen kell DR, akkor minek akarok én menteni bármit is?

Nos, a válasz némileg komikus: Az egyik kliens egy Linux rendszer (SLES 10), amely system VG-je 1 VIO-n található LV-re lett ráhúzva (az LVM kell, ha az ember normálisan akarja skálázni a meglévő erőforrásokat, szóval ez még érthető is). Ahhoz, hogy ezt visszaimádkozzuk 3 út maradt:
- Csinálni egy low level mentést byte szinten a "Guest" System VG-jét tartalmazó PV-ről (azaz a VIO-n lévő LV-ről) valahova a RAID tömbön kívűl, és azt megpróbálni visszatölteni amint az új RAID tömbünket kénytelenek voltunk újra kreálni
- Csinálni egy FS szintű backupot (SLES gyárilag tud ilyet), a RAID tömb 0ról való építése után pedig felhúzni egy alap SLES rendszert, és arra visszatölteni az itt készült backup-ot
- Megpróbálni csinálni egy bootolható ISO file-t, azt odaadni a VIO-nak, majd mint CD/DVD-t kiallokálni a kliens felé, és arról visszatölteni az adatokat (Standard Linux környezetben ez szépen megy is, de amúgy vannak direkt erre a célra elkészített programok is, mint pl a Mondo Rescue)

A baj csak az volt, hogy mind3 út buktatókkal volt kikövezve:
- Bootolható ISO készítés: Az elmélet jó, de az egyik verzióban fel kéne raknom a Mondo Rescue (vagy azzal egyenértékű) progit, ami sajna PPC-re nem elérhető. A Debian féle módszer még működne is, de sajna a pSeries gépeken a boot loader nem grub, hanem Yaboot, ami meg nyomban úgy kezdi, hogy külön FAT16 típusú partíció neki, ami az ISO image-em szempontjából így nem járható.
- Az FS szintű backup azért necces, mert egy teljesen új rendszer felinstallálása szükséges hozzá, ami meg iszonyat nagy macera.
- A low-level (dd) szintű backup tűnt a legjobbnak (és akkor még az LVM struktúra is megmarad), ám amennyiben a RAID5 tömb ezen belül hibásodott meg, akkor meg megint ott vagyok ahol a part szakad..

Nem volt mit tenni: Úgy döntöttem, hogy amit lehet menteni kell (lehetőleg minél többféle képen), mivel a jelenlegi állapotot tutira újra is kell építeni. Tehát csináltam egy dd szintű mentést (LPAR lekapcsolva természetesen), meg egy FS szintűt is, felkészülve a legrosszabbra (az applikációs adatokért nem tudtam semmit se tenni, azt majd remélhetőleg a standard backup process által készített backup lefedi az adat visszaállítás során)

Ez után jött a másik 2 diszk cseréje (pdisk0, pdisk1), majd a halott RAID tömb törlése, és egy új készítése. Mindeközben sűrű miatyánk Mekka irányába..
Amint az új RAID tömb elkészült (immár hiba nélkül) lehetett visszahozni a régi LVM struktúrát, majd nekilendülni az adat visszaállításnak..
És igen.. Mázlim volt.. nettó 40 perc alatt a ~100 GB-os system VG-ről készített dd backup visszatöltődött (yaboot-al együtt), és az LPAR képes volt felbootolni (igaz RC 2ig nem jutott el, de ezen már lehetett segíteni), ergo már csak a tényleges applikációs adatok visszatöltése maradt vissza (meglepő módon azok visszatöltése közben nem nagyon akadt probléma)

Tapasztalatok a jövőre nézve:
- Ha tényleg über fontos adatról/alkalmazásról beszélünk, akkor erőltessük már meg magunkat, és a környezetet tényleg redundánsan alakítsuk már ki
- A RAID 5 addig jó, amíg kevés diszk van alatta. A tömb növekedésével együtt növekszik a teljes tömb meghalásának esélye is (mivel nagyobb az esélye, hogy 1 időn belül 2 aktív diszk hal ki, ahogy itt is történt (nagy eséllyel a használt diszkek ugyan abból a sorozatból valóak, ergo közel ugyan annyi idő alatt is halnak meg))
- Disaster recovery plan még akkor se árt ha van, ha amúgy a rendszer nem indokolja azt meg. A probléma a jelen setuppal az, hogy nem nagyon lehet rá 100%-os plan-t készíteni (ami effektíven használható lenne), a bootolható backup hiánya miatt (személyes véleményem szerint SLES pSeries-re nem való)
- Nagykönyv lehet, hogy létezik, de inkább tekintsünk rá amolyan "Kalóz Kódexként" ami inkább csak útmutatás, mintsem sérthetetlen szabály.. Valami úgy is valamikor el fog romlani, amire persze hogy nem leszünk felkészülve
- A szokásos halandzsa - update, update, update. Tudom, hogy az überfontos applikáció überfontos uptime-al kell üzemeljen, de kalkuláljunk már maintenance window-t is a rendszerhez, hogy az ilyen hülye önszopatásoktól megkíméljük magunkat.
- Murphy sose alszik, és mindig pörgős zenét hallgat :)

2012. április 8., vasárnap

AIX 5.3 + WAS 6.0, Round #2 - Avagy miért is lenne fontos a doksikat karban tartani...

Bő fél éve blogoltam a IV07564-es bogárkáról, ami hajlamos a WAS6.0 adminok életét megkeseríteni. Azóta ugye jó sok idő eltelt, így az ember azt hinné, hogy ezt az issue-t is le lehet zárni. Főként mert a bug az AIX 5.3 TL12 SP05ben már elvileg javítva van.

Mint ahogy a hivatalos doksik is írják (IV07564, Java application hang after applying AIX maintenance) a hiba csak a 5.3.12.1-es szinten lévő bos.rte.libpthreads-et érinti, és mivel az 5.3 TL12 SP05-ben már a 5.3.12.2-es van, így lelki nyugalommal mondhatjuk, hogy igen, ez a hiba már tényleg nem fenyegeti a WAS6 rendszereket futtatók életét..

A valóság sajnos az, hogy holott minden a fentiek mellett szól, a gyakorlat még is csak a makacs tényeket részesíti előnyben. Hogy megértsük hol vált külön az elmélet a gyakorlattól, nézzük át kicsit ennek a bugnak az életét (illetve azt is ami nem egészen van dokumentálva). Mázlira a file nevek meglehetősen beszédesek:

IV07564s03 - IV07564s03.111005.epkg.Z
Ez alapján ez a file még 2011.10.05.-én kijött (Anno még én is ezt a verziót töltöttem le). A fixbe belekukkantva az alábbi Abstract-ot találjuk az ecfile-ban: "Ifix for apar IV07564 at 53X SP04."

IV07564s04 - IV07564s04.111005.epkg.Z
Hibajavítás az előző verzióra. A filenév alapján ugyan azon a napon kreálták. A fix-be belenézve az Abstract is azonos (fix for apar IV07564 at 53X SP04.)

IV07564s05 - IV07564s05.111107.epkg.Z
Na innen indul a buli. Az ecfile-ban itt már a "Ifix for apar IV07564 at 53X SP05." leírást olvashatjuk, ami azt jelenti, hogy ez a fix már az SP5-re lett kihozva. A filenév alapján ezt a fix-et 2011.11.07.-én készítették

A probléma ott kezdődik, hogy a hivatalos doksik - amik erre a bugra mutatnak - nem követték a folt fejlesztéseinek változásait:

Java application hang after applying AIX maintenance - Modified date: 2011-10-27
IV07564: HANG IN _EVENT_NOTIFY(). - Modified date: 2011-12-09

- Az elsőnél egyértelműen látszódik, hogy a doksi leragadt a IV07564s03/IV07564s04(?)-es fixnél, így aki az alapján próbál információt szerezni alapból megszívta.
- A másodiknál látszik, hogy valaki Dec 09.-én módosított valamit, de ha megnézzük a letöltési helyre mutató linket (ftp://public.dhe.ibm.com/aix/efixes/iv07564/) nyomban láthatjuk, hogy a file feltöltési dátuma azonos, így gondolom csak egy új lokációt adtak meg a file számára, de elfelejtették a doksi többi részét frissíteni

A vicc az, hogy az ember a turpisságra csak akkor jön rá, ha ténylegesen bele is néz a fixbe és az ecfile-t végigbogozva rájön, hogy ...
- A doksik nem up-to-date-ek
- Az 5.3 TL12 SP5 is érintett a problémában
- A 6.0-ás WAS rendszerek lehet pont ezért hullanak mint a legyek 5.3 alatt (Azt azért hozzá kell persze tenni, hogy a 6.0-ás WAS Supportja 2010 Szeptember 30.-án lejárt így ne csodálkozzanak azok akik outdated SW esetén inkompatibilitást tapasztalnak )
- Ezt lehet le kéne blogolni, hogy más ne szívjon vele annyit :)

For the record - Az eredeti blogbejegyzésemben szóltam, hogy AIX 6.1 is érintett - ott ezeket az APARokat tessék keresni
AIX 6.1 TL07 - IV09681
AIX 6.1 TL06 - IV08153
AIX 6.1 TL05 - IV07839

# Megjegyzem, hogy a 6.1-es AIX-hez kiadott javításokat nem tudtam átnézni, így a hiba ott is fenn álhat (bár az announcement-ek modification date-je azért ad némi bizalomra okot)

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.

2011. október 16., vasárnap

Elvitte a cica.. De hova bújt???

Pénteken olyan hibába botlottam bele, hogy azt hittem ilyen nem is létezhet.. Így hát amikor sikerült megtalálnom mi és hogy is történ(hetet)t persze, hogy úgy gondoltam, hogy ezt le kell blogoljam.. Íme egy némileg összeszedett beszámoló arról, hogy mi és hogy történt a probléma felderítése során:

Nos hát.. Alap probléma: Restart után a szerveren nem használható a /dev/null...
Nézek ki a fejemből, hogy ez miért és hogy, de a hibaüzenet egyértelműen fogalmaz:
server@user:/home/user $ ls > /dev/null
Permission denied
ksh: /dev/null: cannot create
Gyorsan átmásztam root-ba, megnéztem mi a helyzet a környéken:
server@root:/home/root # ls -ld /dev/null
crw-rw-rw-    1 root     system        2,  2 Oct 15 16:29 /dev/null
server@root:/home/root # ls -ld /dev
drw-------    5 root     system       356352 Oct 15 15:00 /dev
Aham.. hogy csak a root-nak van valami joga a mappára.. Ki lehetett az a hülye, aki átlőtte??? Na mind1, rakjuk helyére..
server@root:/home/root # chmod 775 /dev
server@root:/home/root # ls -ld /dev
drwxrwxr-x    5 root     system       356352 Oct 15 15:00 /dev
Kicsit matattam még a gépen, tettem-vettem, amikor is egy újabb parancs kiadásakor ismét ugyan ebbe a hibába botlottam (Permission denied).. Nézem ismét a /dev jogait.. megint 600... Hát mondom ilyen nincs.. valaki ilyen hülye, és még aktívan a gépen is van? Ha megtalálom nem hogy a root jogot veszem el tőle, hanem még a kezét is letöröm.. Ez a kis "lelkesedés" addig tartott, amíg észre nem vettem, hogy rajtam kívül nincs senki a gépen.. Feltételezve, hogy én nem műveltem ilyen hülyeséget néztem hogy akkor ez most WTF.. Valaki távolról, vagy hogy??? Hát mondom akkor játsszuk ezt..

Visszaállítottam a /dev jogait 775-re, majd kb 5-10 mp-enként visszaellenőriztem 'ls -ld /dev'-el, hogy mi is lehet itt.. Kb ezt kaptam:
server@root:/home/root # ls -ld /dev
drwxrwxr-x    5 root     system       356352 Oct 14 15:10 /dev
server@root:/home/root # ls -ld /dev
drwxrwxr-x    5 root     system       356352 Oct 14 15:10 /dev
server@root:/home/root # ls -ld /dev
drwxrwxr-x    5 root     system       356352 Oct 14 15:10 /dev
server@root:/home/root # ls -ld /dev
drw-------    5 root     system       356352 Oct 14 15:10 /dev
Hát mondom ilyen nincs.. valaki garázdálkodik itt, vagy mifene?? Hát a jó nénikéjét.. Fogjuk már meg..
Első gondolatom az volt, hogy az audit subsystem tökéletesen megfelel ennek kiderítésére.. De nézzük hogy is lehet ezt kivitelezni?
- /etc/security/audit/objects alá fel lehet ugyan venni a /dev-et, de az objects alatt csak read/write/execute event-eket lehet vizsgálni.. Itt meg látható, hogy az nem segítene, ergo ez nem nyert hangszórót
- Gondoltam, hogy ha valami itt a /dev jogait piszkálja, akkor a chmod-ot kell hívnia kötelezően.. Hát akkor induljunk el ebbe az irányba: Vegyünk fel a chmod parancsot az objects alá az alábbi módon:
/usr/bin/chmod:
 x = "CHMOD_USE"
Illetve a /etc/security/audit/events alá az új eventünket:
* chmod execution
  CHMOD_USE = printf "pid: %d, command: %s"
Amint ezzel kész vagyunk indítsuk újra az audit subsystem-et:
server@root:/ # audit shutdown
auditing reset
server@root:/ # audit start
server@root:/ # audit query |grep auditing
auditing on
server@root:/ # audit query |tail -2
 /usr/bin/chmod:
  x = "CHMOD_USE"
Oksa.. Tehát akkor elvileg ez is a helyén van.. akkor már csak az kell, hogy realtime nézhessük mi is folyik a gépen. Ezt az alábbi módon oldottam meg:
server@root:/ # /usr/sbin/auditstream | /usr/sbin/auditpr -t0 -heRltc |grep CHMOD
Ezzel a paranccsal lényegében direktbe szűrhetek arra, amire szeretnék.. Ergo fogtam magam, nyitottam egy újabb terminált, majd ott követtem a /dev változásait, miközben ez a stream az 'egyes" terminálon szépen futott. Direkt átírtam a chmod jogait ismét 775-re (megint 600on volt), és konstatáltam, hogy az audit igen is látja a módosításom:
CHMOD_USE       OK          root  Fri Oct 14 17:06:52 2011 chmod
Ezt követően csak vártam, és a másodlagos terminálon követtem a /dev esetleges változásait.. Egészen addig amíg a terminálon láttam, hogy a jogok megváltoztak, de az audit ebből semmit nem vett észre... WTF!? Audit stop, mit szúrtam el?? Lehet van máshol is chmod a rendszeren???
server@root:/ # find / -name chmod -type f -ls
 1057    9 -r-xr-xr-x  1 bin       bin           9216 Jul  9  2009 /usr/bin/chmod
Nincs, csak ez az egy.. Akkor meg hogy a fenébe??? Na jó, mind1.. Az auditról tudni illik, hogy azért nem csak az objects file-ja használható, hanem alapértelmezetten az events-ek között jó pár más event is előre van definálva, mint például ezek:
*       chmod()
        FILE_Mode = printf "mode: %o filename %s"

*       fchmod()
        FILE_Fchmod = printf "mode: %o file descriptor %d"
A rendszer alaptelepítés esetén ezeket nem használja (tekintve, hogy iszonyat sok adatot is generálnának), de nekem most ideiglenesen ezek pont jónak tűntek.. Meg is néztem, hogy a configon belül ezek hol vannak definiálva, és a classes alatt gyönyörűen ott sorakozott az alábbi sor:
files = FILE_Open,FILE_Read,FILE_Write,FILE_Close,FILE_Link,FILE_Unlink,FILE_Rename,FILE_Owner,FILE_Mode,FILE_Acl,FILE_Privilege,DEV_Create
A FILE_Mode alapból ott volt a files class-ban, viszont a FILE_Fchmod nem, így azt is felvettem (biztosra megyek, úgy voltam vele), így kaptam ezt a sort:
files = FILE_Open,FILE_Read,FILE_Write,FILE_Close,FILE_Link,FILE_Unlink,FILE_Rename,FILE_Owner,FILE_Mode,FILE_Acl,FILE_Privilege,DEV_Create,FILE_Fchmod
Ez után már csak az kellett, hogy ezt a class-t felvegyem a users szekció alatt a root-hoz az alábbi módon:
users:
        root = general,files
        default = objects
Rendicsek.. Akkor ez is megvan.. Biztos ami biztos kiszedtem az objests-ből előzőleg definiált chmod figyelést is, majd újraindítottam az auditot, és eljátszottam pontosan ugyan azt mint előzőleg -> egyik konzolon futott az auditing stream-je (immár grep -E "FILE_Mode|FILE_Fchmod" szűréssel), a másikon meg a /dev vizsgálata. Átállítottam ismét a /dev jogait 775-re (ekkor már kifejezetten idegesített az issue), majd örömmel konstatáltam, hogy az audit észrevette ezt a súlyos cselekményt:
FILE_Mode       OK          root  Fri Oct 14 18:05:25 2011 chmod
Újabb 1-2 percnyi várakozás, és minden elvárás ellenére ugyan az az eredmény!!! -> Az audit nem veszi észre azt ami ezt csinálja, csak azt amit én manuálisan ráengedek.. Ekkor sejtettem, hogy ez valószínű nem valami user hülyesége, hanem lehet valami bug, mert a forkot az audit tuti észrevenné.

Innentől viszont nyilvánvalóvá vált, hogy az audit e célra itt nem fog bejönni.. Kénytelen voltam elővenni a nagyágyút: trace
Szerencsémre a trace azért meglehetősen jól használható AIX alatt, feltéve ha az ember tudja hogy is használja.. Az már csak hab a tortán, hogy van egy csomó előre definiált trace event group, amik közül az alábbiak közül választhattam (A / JFS2 típusú)
server@root:/ # trcrpt -G |grep jfs2
jfs2 - JFS2: all JFS2 operations (reserved)
jfs2meta - JFS2: metadata operations (reserved)
jfs2user - JFS2: userdata operations (reserved)
jfs2snap - JFS2: snapshot operations (reserved)
Megvan azért annak az előnye, ha nem kell az embernek fejből tudnia az összes hookot :)) Ami viszont engem illetett - úgy voltam vele, hogy ennyi szívás után nem szórakozok: minden JFS2 módosításról tudni akarok!!! Ergo fogtam magam, és az alábbi módon jártam el:
server@root:/ # chmod 775 /dev
server@root:/ # ls -ld /dev
drwxrwxr-x    5 root     system       356352 Oct 15 15:00 /dev
server@root:/ # trace -a -J jfs2 -o /tmp/trc_raw 
server@root:/ # trcon
A másik konzolon meg az alábbi kis while ciklussal vártam, hogy mikor is történik pontosan (!) a váltás:
server@root:/ # while true;do echo "$(date +"%Y.%m.%d %H:%M:%S") $(ls -ld /dev)";sleep 1;done
2011.10.14 18:42:00 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:42:01 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:42:02 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:42:03 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:42:04 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:42:05 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:42:06 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:42:07 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:42:08 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:42:09 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:42:10 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:42:11 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:42:12 drw-------    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:42:13 drw-------    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:42:14 drw-------    5 root     system       356352 Oct 14 18:30 /dev
Amint erre a pontra jutottam nyomban le is állítottam a trace-t, majd amikor állítottam volna le ezt a while ciklust konstatálhattam, hogy a CTRL+C nem működik!! -> Mint kiderült: Ha belépéskor nincs a /dev-nek elég joga, akkor a CTRL+C nem fog menni, hiába van jól belőve az 'intr' érték az stty alatt:
server@root:/ # stty -a |grep intr
intr = ^C; quit = ^\; erase = ^?; kill = ^U; eof = ^D; eol = 
Amint átállítottam a /dev jogait, és nyitottam egy új shell-t nyomban visszaállt minden a régibe az adott shellen belül.. A másikon meg killelhettem a ciklust.

Na mind1.. Nézzük azt a trace-t
server@root:/ # trcoff
server@root:/ # trcrpt -O "exec=on,pid=on" /tmp/trc_raw > /tmp/trc_raw.out
server@root:/ # ls -l /tmp/trc_raw.out
-rw-------    1 root     system      7213429 Oct 14 18:26 /tmp/trc_raw.out
Kb sejthetitek miért is nem olyan gyakori a trace használata ebből már: kevesebb mint fél perc alatt majd 7 MB adat generálódott a riportban! Na de, ha már megvannak az adatok, akkor igen is nézzük át mi és hogy lehetett.. A probléma csupán az, hogy ~7 MB-ot átnyálazni kicsit sokáig tart, meg jelen esetben amúgy se célravezető.. Jobb volt inkább megnézni, hogy mely processek használták a /dev-et..

Ehhez első körben tudni kell a /dev inode számát, hogy legalább legyen mire szűrnünk:
server@root:/tmp # istat /dev
Inode 12289 on device 10/5      Directory
Protection: rw-------   
Owner: 0(root)          Group: 0(system)
Link count:   5         Length 356352 bytes

Last updated:   Fri Oct 14 18:30:10 2011
Last modified:  Fri Oct 14 18:30:10 2011
Last accessed:  Fri Oct 14 18:30:27 2011
Oks.. Tehát 12289.. Ezt nyomban át is kell váltanunk hexába, ami meg 3001.. Ezt a számot használva meg könnyen szűrhetünk is. Ha viszont csak így magában tesszük, akkor ilyen hosszú rettentő sorokat kapunk:
server@root:/ # grep -w 3001 /tmp/trc_raw.out |head -5
4DF --1-           -1            0.003434251       0.001326                   JFS2 iget: vp = F100011010C3B3E8, count = 0001, ino = 3001, dev = 8000000A00000005, getcaller = 2CF754
4DF --1-           -1            0.003444816       0.005402                   JFS2 iput: vp = F100011010C3B3E8, count = 0000, ino = 3001, nlink = 0005, getcaller = 2CF9DC
4DF --1-           -1            0.003447171       0.000623                   JFS2 iget: vp = F100011010C3B3E8, count = 0001, ino = 3001, dev = 8000000A00000005, getcaller = 2CF754
4DF --1-           -1            0.003452763       0.003297                   JFS2 iput: vp = F100011010C3B3E8, count = 0000, ino = 3001, nlink = 0005, getcaller = 2CF9DC
4DF --1-           -1            0.003455013       0.000683                   JFS2 iget: vp = F100011010C3B3E8, count = 0001, ino = 3001, dev = 8000000A00000005, getcaller = 2CF754
Ergo lehet jobban járunk ha inkább a statisztikára vagyunk kíváncsiak:
server@root:/ #  grep -w 3001 /tmp/trc_raw.out |awk '{print $2}'|sort|uniq -c
   761 --1-
   2 cdromd
   36 init
Mindjárt jobb.. Tehát.. 761 hozzáférés a kernel részéről, 2 hozzáférés a cdromd-től, 36 az inittől.. A kernellel ugye nem sokat tudok kezdeni (az meg csak nem vetemedik ilyenre!), ergo maradt a másik 2 - cdromd, meg init.. Első körben így hát fogtam magam, 'stopsrc -s cdromd'-vel leállítottam a daemon-t, visszalőttem a /dev-et 775-re, majd vártam, hogy változik e a jogosultsága.. Változott.. Ergo akkor nem a cdromd.. Vissza is kapcsoltam.

A másik lehetőség az init volt.. Erről ugye annyit illik tudni, hogy a /etc/inittab file-ban tárolt bejegyzések alapján ténykedik. Amennyiben egy program/script respawn-ra van állítva, akkor az időről időre meg is hívódik, ami meg is magyarázná, hogy hogy lehet az, hogy user interakció nélkül változzon a /dev jogosultsága.. Nade a baj az, hogy az inittab-ban azért csak úgy nem turkálunk, a cdromd-hez hasonló teszteléseket (állítsuk le, aztán nézzük meg jó lesz e úgy) meg itt már nem biztos hogy jó ötletnek tartanám..

Azt viszont tudnunk kell, hogy amennyiben az inittab indít valamit, úgy annak a bejegyzése beleíródik a wtmp-be is.. Én meg az előző mérésemből tudtam a pontos időpontot (18:42:12), így az alapján már könnyen el lehetett indulni:
server@root:/ # cat /var/adm/wtmp |/usr/sbin/acct/fwtmp |grep "Fri Oct 14 18:42:1[012]"
         cons                         8 155664 0000 0001 1318614131                                  Fri Oct 14 18:42:11 2011
cons     cons                         5 58206 0000 0000 1318614131                                  Fri Oct 14 18:42:11 2011
         cons                         8 58206 0000 0001 1318614131                                  Fri Oct 14 18:42:11 2011
cons     cons                         5 58208 0000 0000 1318614131                                  Fri Oct 14 18:42:11 2011
         cons                         8 58208 0000 0001 1318614131                                  Fri Oct 14 18:42:11 2011
cons     cons                         5 221186 0000 0000 1318614131                                  Fri Oct 14 18:42:11 2011
         cons                         8 221186 0000 0001 1318614132                                  Fri Oct 14 18:42:12 2011
cons     cons                         5 57910 0000 0000 1318614132                                  Fri Oct 14 18:42:12 2011
         cons                         8 57910 0000 0001 1318614132                                  Fri Oct 14 18:42:12 2011
cons     cons                         5 221188 0000 0000 1318614132                                  Fri Oct 14 18:42:12 2011
         cons                         8 221188 0000 0001 1318614132                                  Fri Oct 14 18:42:12 2011
cons     cons                         5 221190 0000 0000 1318614132                                  Fri Oct 14 18:42:12 2011
Aham.. Tehát a cons bejegyzés a ludas.. Az meg a getty-t hívogatja..
server@root:/ # lsitab cons
cons:0123456789:respawn:/usr/sbin/getty /dev/console
Respawn is ahogy vártam, de most komolyan a getty okozna nekem ilyen gondokat? Hát nézzük meg:
server@root:/tmp # ls -ld /dev; /usr/sbin/getty /dev/console;ls -ld /dev
drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
/dev/: TSM was unable to open port "/dev/"
drw-------    5 root     system       356352 Oct 14 18:30 /dev
Aham.. Hát most vagy én vagyok nagyon balszerencsés, és pont abban az időben történt más is, vagy a getty tényleg ilyen problémákkal küszködik.. (A TSM-es hibára még visszatérek). Tekintve, hogy a 'getty /dev/console'-t manapság inkább csak virtual console-okhoz használják, így szívfájdalom nélkül kikapcsoltam, majd vártam, hogy történjen valami:
server@root:/tmp # chitab cons:0123456789:off:"/usr/sbin/getty /dev/console"
server@root:/tmp # chmod 755 /dev
server@root:/ # while true;do echo "$(date +"%Y.%m.%d %H:%M:%S") $(ls -ld /dev)";sleep 1;done
2011.10.14 18:46:11 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
......
2011.10.14 18:46:40 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
...
2011.10.14 18:46:57 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
...
2011.10.14 18:47:22 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
...
2011.10.14 18:47:38 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
...
2011.10.14 18:47:58 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
...
2011.10.14 18:48:20 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:48:21 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:48:22 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:48:23 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:48:24 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:48:25 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:48:26 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:48:27 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:48:28 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
2011.10.14 18:48:29 drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
Ctrl+C.. Őszinte leszek.. Még mindig nem értettem a dolgot.. Ezek szerint tényleg a getty okozza a problémát.. De miért?? Nézzük a konzol beállításokat:
server@root:/tmp # lscons -a
 current = NULL
 console_logname = /var/adm/ras/conslog
 console_logsize = 32768
 console_logverb = 1
 console_tagverb = 0
Na jó.. Beismerem.. Ez tényleg nem egészséges.. Ezt azonnal orvosolni kell:
server@root:/tmp # chcons -a login=enable /dev/vty0
chcons: Console login cannot be enabled because the console device
        is not an available lft, tty, or vty.
Hö??? WTF??? Mi van a vty0-val?
server@root:/tmp # lsdev -Cctty
vty0 Defined  Asynchronous Terminal
Jah hogy úgy.. Na ezt rántsuk már be akkor:
server@root:/tmp # cfgmgr -l vty0
Method error (/etc/methods/cfgtty -l vty0 ):
        0514-040 Error initializing a device into the kernel.
Na menj a tudod hova... Van más is amiről tudnom kéne??
server@root:/ # lsdev |grep vs
vsa0        Defined            LPAR Virtual Serial Adapter
vsa1        Defined            LPAR Virtual Serial Adapter
vsa2        Available          LPAR Virtual Serial Adapter
server@root:/ # lsdev |grep vty
vty0        Defined            Asynchronous Terminal
Aham.. LPAR profil alapján csak 1 Virtual Serial Adapter van (ezek szerint az lesz a vsa2), de akkor ez miért lát 3at?? Na mind.. Gyomláljunk, mert ez így gázos:
server@root:/ # for i in vty0 vsa2 vsa1 vsa0;do rmdev -dl $i;done
vty0 deleted
vsa2 deleted
vsa1 deleted
vsa0 deleted
server@root:/ # cfgmgr
server@root:/ # lsdev |egrep "vty|vsa"
vty0        Available          Asynchronous Terminal
vsa0        Available          LPAR Virtual Serial Adapter
server@root:/ # chcons -a login=enable /dev/vty0
chcons: console login enabled, effective on next system boot
chcons: console assigned to: /dev/vty0, effective on next system boot
Oks.. Mindjárt jobb.. Console-al mi van?
server@root:/ # pstart
console DISABLE
vty0 ENABLE
Na ez még gázos lehet.. Akkor ezt is rakjuk helyre:
server@root:/ # penable console
server@root:/ # pstart
console ENABLE
vty0 ENABLE
Ez után ismét megnéztem mi és hogy áll.. Sajna azt kellett tapasztaljam, hogy a penable igaz, hogy helyére rakta a console-t, viszont az inittab-ban is újra engedélyezte a cons bejegyzést.. Ez miatt ismét rakhattam off-ba, illetve lőhettem vissza a /dev-et 775-re.. Viszont sajna a jelek szerint a getty még mindig nem ment normálisan:
server@root:/tmp # ls -ld /dev; /usr/sbin/getty /dev/console;ls -ld /dev
drwxrwxr-x    5 root     system       356352 Oct 14 18:30 /dev
/dev/: TSM was unable to open port "/dev/"
drw-------    5 root     system       356352 Oct 14 18:30 /dev
Hát jó.. akkor nem maradt más restart.. Ami láss csodát.. Megoldotta a problémát!
server@root:/tmp # ls -ld /dev; /usr/sbin/getty /dev/console;ls -ld /dev
drwxrwxr-x    5 root     system       356352 Oct 14 19:10 /dev
drwxrwxr-x    5 root     system       356352 Oct 14 19:10 /dev

Éljen.. akkor problem solved.. Na de azért bennem felmerült 1-2 dolog.. Az első, hogy mint látható, most a TSM nem dobott hibát. Tekintve, hogy a TSM-es hiba direktben a /dev-re hivatkozott, így erősen esélyesnek tartom, hogy a problémának ehhez is köze lehet.. Tekintve, hogy ez egy TSM szerver, így nem csodálkoznék, ha ez egy TSM bug lenne, viszont a neten körbeszaglászva ilyen, vagy ehhez hasonló hibaleírást véletlenül se sikerült találnom.. A gyanúmat még jobban alátámasztja az, hogy a getty által piszkált file-ok a /dev alatt default 622-es jogot kapnak (hacsak ezt az ODM-ben nem bíráljuk felül, de ilyen itt nem volt)
Az viszont a probléma ellen szól, hogy a TSM-nek semmi köze nem szabadna legyen ezen a szinten a rendszerhez, pláne nem a getty futtatásakor. Így az is elképzelhető, hogy ez is csak egy a sok side affect közül (mint pl a CTRL+C-s hiba) ami amúgy egy getty-os bug.
Mindazonáltal a hiba meglehetősen furcsa volta, illetve a hiba keresési mód miatt úgy gondoltam, hogy ez az írás megér egy blog bejegyzés (tudom - jó hosszú lett)

2011. október 9., vasárnap

AIX mounting issue

Kicsit régebbi eset(2009.08), de gondoltam inkább lebloggolom, mintsem az enyészeté legyen, mert annál azért többet ér :)

Nos hát.. Alapvető probléma a következő: A rendszer indulásakor egy csomó filerendszer nem jön fel normálisan, holott a /etc/filesystems alatt szépen be van állítva, hogy azoknak bizony fel kell jönniük. A Volume Group szépen aktiválódik, de az alatta lévő FS-ek a rendszer indulásakor nem jönnek fel (Ha manuálisan mountoljuk őket, akkor viszont igen)

Kiegészítő információk:
- Az AIX kicsit régi a gépen (5300-10-01-0921) de ez nem indokolja a rendszer hibáját.
- A bootolás után a console log ilyen randaságokat tartalmaz:
0 Sun Aug 16 16:43:35 BST 2009 mount: 0506-324 Cannot mount /dev/lv_ap02n8log on /vfs=jfs2log=/dev/loglv27: A file or directory in the path name does not exist.
0 Sun Aug 16 16:43:35 BST 2009 mount: 0506-324 Cannot mount /dev/lv_ap02n2temp01 on /dev=/dev/lv_ap02n2data02log=/dev/loglv20: A file or directory in the path name does not exist.
0 Sun Aug 16 16:43:35 BST 2009 mount: 0506-324 Cannot mount /dev/lv_ap02n3data02 on /dev=/dev/lv_ap02n2temp02log=/dev/loglv20check=false: A file or directory in the path name does not exist.
0 Sun Aug 16 16:43:35 BST 2009 mount: 0506-324 Cannot mount /dev/lv_ap03n9log on /vfs=jfs2: A file or directory in the path name does not exist.

Mint az látszik a console logból a rendszer össze vissza kavarva próbál valami mount félét össze hozni, de nagyon kevés sikerrel.
Na de a kérdés.. Miért, és hogy?
Ehhez első körben vizsgáljuk meg, hogy mi (és hogy) is lenne a felelős ennek folyamatnak a lezongorázásáért:

A folyamat alapvetően egyszerű: a rendszer IPL-je során amint átvált a rendszer rc2-be nyomban elkezdi a /etc/inittab-ot feldolgozni, illetve az ott feltüntetett parancsokat/scripteket végrehajtani. Az egyik ilyen alap script a /etc/rc, ami a mountolásért is felel. Az akkor rendszeren az alábbi kód volt ezért a felelős (megjegyzés - a kód verziószáma 1.20.1.7 - ez még később fontos lesz)

# Perform file system checks
# The -f flag skips the check if the log has been replayed successfully
fsck -fp

# Perform all auto mounts
dspmsg rc.cat 4 ' Performing all automatic mounts \n'

cat /etc/filesystems | tr -d ' ' | tr -d '\t' | grep -vp "vfs=nfs" | grep -vp "vfs=cachefs"> /tmp/fs1.$$

# Collecting entries except nfs
lines=`wc -l /tmp/fs1.$$ | awk '{print $1}'`

# Calculate the number of lines
cnt=1

# Remove the file 'fs2.$$' if it already exists
if [ -f /tmp/fs2.$$ ]
then
        rm -f /tmp/fs2.$$
fi

# Compare each line in the file '/tmp/fs1.$$'
# If it is a comment line or just having the filesystem name,
# just write it to '/tmp/fs2.$$'
# Otherwise, add a tab before that line and write it to '/tmp/fs2.$$'

while [ $cnt -le $lines ]
do
        cat /tmp/fs1.$$ | head -$cnt | tail -1 | grep "^[\*/]"  1> /dev/null
        if [ $? -eq 0 ]
        then
                cat /tmp/fs1.$$ | head -$cnt | tail -1 >> /tmp/fs2.$$
        else
                param=`cat /tmp/fs1.$$ | head -$cnt | tail -1`
                echo "\t"$param >> /tmp/fs2.$$
        fi
        cnt=`expr $cnt + 1`
done
mount /tmp/fs2.$$ /etc/filesystems
mount all
umount /etc/filesystems
rm -f /tmp/fs1.$$ /tmp/fs2.$$

Nah.. mit is látunk itt...
- Első körben a rendszer létrehoz egy /tmp/fs1.$$ file-t ($$ a PID szám, amivel maga a /etc/rc fut), amit aztán majd alapnak fog használni. A file-ból minden tab és szóköz hiányzik, illetve a cachefs-eket is kikapja belőle a grep -vp.
- Aztán egy $lines változót használva a rendszer megnézi, hogy az így keletkezett file hány soros (bár sztem kicsit undorítóan csinálja, de hát ízlés kérdése).
- Mindezek után egy counter-t használva ($lines értékéig) egy teljes while ciklus indul, ami egy (szerintem szintén undorító módon) sorról-sorra végigmegy, és megnézi, hogy az adott sor '*'-al, avagy '/'-el kezdődik e (grep visszatérési értéke). Amennyiben igen, úgy az adott sor átkerül egy /tmp/fs2.$$ file-ba. Amennyiben mégse így történne akkor is, csak az adott sor kap maga elé egy tabulátort.
- Amint a ciklus lefut egy meglehetősen furcsa módszerrel a /tmp/fs2.$$-ban lévő FS-eket mountolja a rendszer (figyelem - a /etc/filesystems helyére felülmountolódik a /tmp/fs2.$$ ), majd a standard mount all parancsal minden a file-ban szereplő FS mountolódik (aminek a mount paramétere nem 'false').
- Amint ezzel is kész feloldja az előző mountot, majd törli a temporary file-okat.

A módszer kicsit tényleg furcsán néz ki (nekem főleg a sorról-sorra végigmenős módszertől borsódzik a hátam), viszont elméletben működnie kellett volna.. Akkor hol volt a probléma?? Nos.. végeztem pár tesztet, majd a szemem fennakadt, amikor nem az általam várt eredmények jöttek ki:

A használt script a következő volt:
#!/bin/ksh
set -x
lines=`wc -l /tmp/fs1.temp | awk '{print $1}'`
cnt=1

while [ $cnt -le $lines ]
do
        cat /tmp/fs1.temp | head -$cnt | tail -1 | grep "^[\*/]"  1> /dev/null
        if [ $? -eq 0 ]
        then
                cat /tmp/fs1.temp | head -$cnt | tail -1 >> /tmp/fs2.temp
        else
                param=`cat /tmp/fs1.temp | head -$cnt | tail -1`
                echo "\t"$param >> /tmp/fs2.temp
        fi
        cnt=`expr $cnt + 1`
done
Lényegében azonos a standard scriptel, az eredmény (/tmp/fs2.temp) viszont nem az volt amit vártam:
/var:
dev=/dev/hd9var
vfs=jfs2
    log=/dev/hd8
    mount=automatic
check=false
type=bootfs
    vol=/var
    free=false
quota=no

/tmp:
    dev=/dev/hd3
    vfs=jfs2
log=/dev/hd8
mount=automatic
check=false
vol=/tmp
free=false
quota=no

/proc:
    dev=/proc
    vol="/proc"
    mount=true
    check=false
    free=false
    vfs=procfs
Mit látható.. A TAB-ok egy csomó helyen nem kerültek a helyükre.. Na akkor nézzük meg azt az elágazást kicsit közelebbről:
cat /tmp/fs1.temp | head -$cnt | tail -1 | grep "^[\*/]"  1> /dev/null
if [ $? -eq 0 ]
then
        cat /tmp/fs1.temp | head -$cnt | tail -1 >> /tmp/fs2.temp
else
        param=`cat /tmp/fs1.temp | head -$cnt | tail -1`
        echo "\t"$param >> /tmp/fs2.temp
fi
Tehát.. Ha a $? (előző parancs (grep) Return Code-ja) 0 akkor csak rakja bele, ha meg nem akkor toldja meg egy tabbal.. Hát jó. csináljunk egy kis tesztet:
server:root # while true;do cat /tmp/fs1.temp | head -172| tail -1 | grep "^[\*/]"  1>/dev/null;echo $?;done
1
2
13
13
13
13
13
13
És kb itt nyomtam Ctrl+C-t..

Mit is csináltam? - egy végelenített ciklust, amikor is folyamatosan ugyan azt az adatot kértem ki (head+tail) majd megnéztem a grep return code-ját.. Az viszont azonos adat esetén (172. sor) különböző eredményt produkált! Wattafák???

Nos.. Mint kiderült sikerült belefutni egy meglehetősen érdekes issue-ba. Ennek az issue-nak neve is volt: IZ43276: KSH MAY RETURN INCORRECT RETURN CODE FOR PIPED COMMANDS APPLIES TO AIX 5300-11

Aha... Hogy úgy... Én is üdvözöllek.. A problémámon ez a tudás akkor viszont még nem segített.. A patch-et csak 2010ben adták ki, ami azt jelentette, hogy én 2009ben még csak feliratkozhattam a fix "hírlevél mondóra" és várhattam, hogy javítják a hibát..

Viszont mint kiderült azért volt kerülőút: Az AIX 5.3 TL6-tól (TL10-en van a rendszer, emlékeztek? :) a /etc/rc file már a 1.20.1.9 verzión volt, ami ugyen ezt a problémát (FS-ek mountolása) sokkal szebben oldotta meg:

# Remove the file 'fs1.$$' if it already exists
rm -f /tmp/fs1.$$

# handle the egrep line carefully: between each pair of brackets is a tab
# followed by a space, and the tab may get lost if you copy and paste the line
egrep -vp "^[ ]*vfs[ ]*=[ ]*(cachefs|nfs|cifs)[ ]*$" \
/etc/filesystems > /tmp/fs1.$$

mount /tmp/fs1.$$ /etc/filesystems
mount all
umount /etc/filesystems
rm -f /tmp/fs1.$$

Éljenek a Reguláris kifejezések.. Ennek a kódnak köszönhetően pedig (mivel nem használ hülye visszatérési értékeket) a mount problémám megoldódott (persze a rendszeren lévő további scriptek amik erre támaszkodtak ettől még szívhatták).

Egy kérdés maradt csak nyitva - Ha ez TL6tól elérhető volt, akkor miért nem ez a verzió volt elérhető a TL10-es AIX alatt is?

A válasz persze "prózai" - A fejlesztők szerint a /etc/rc file-t a customer (ha nem is nyugodtan, de.. ) bármikor szerkesztheti, így úgy gondolták, hogy az upgrade során ezt a file-t inkább ne piszkálják (hisz új funkciót amúgy se hoz) upgrade során. Ergo ha a rendszer egy régebbi szintről ( < TL6 ) lett felhúzva TL10-re, akkor az upgrade véletlenül se fogja a frissebb file-t a helyére pakolni. Max akkor ha a rendszert már az elejétől fogva TL6, vagy afölötti verzióval telepítették (ergo az újabb /etc/rc már alapból része a telepítő csomagnak)..

Igen.. Én is örültem amikor megtudtam :)

2011. szeptember 15., csütörtök

AIX 5.3 TL12 SP04 + WAS6 == Oops...

Na jó.. Nem kernel Oops, de attól még fájó élmény a WAS-nak (Web's Fear Application Server az én olvasatomban). A helyzet ugyan is az, hogy AIX 5.3 TL12 SP04, illetve AIX 6.1 TL06 SP4 alatt a WAS6 által használt 1.4.2-es JRE nem érzi annyira jól magát, és a garbage collector hajlamos lockokba kergetni magát, ami aztán lassan a WAS halálát eredményezi.

Angolul tudóknak íme a 6.1es AIX-hoz kiadott tájékoztató: https://www-304.ibm.com/support/docview.wss?uid=swg21514823
# Note - az eredeti tájékoztató hibás, és az 5.3 alatt is totál ugyan ez a hiba jön elő
Abstract: WebSphere Application Server (WAS) is hanging after running successfully for a while. The problem happens intermittently, and there is no particular pattern that triggers this behavior.

Symptom: After starting and running successfully for a while, the WebSphere Application Server hangs. When this hang occurs, WebSphere Application Server becomes unresponsive and needs to be killed and restarted.

Cause: This is not a software problem with Information Server or WebSphere Application Server. A defect was introduced within the AIX operating system fix for APAR IZ93027 which causes WebSphere Application Server 6.0.2 to hang intermittently. This APAR is included in the TL06, SP04 package for AIX 6.1, so the issue appears after upgrading AIX to this technology and service pack level.

Resolving the problem : The issue can be solved immediately by downgrading AIX 6.1 to TL06, SP03. This downgrade is accomplished by reinstallation of service pack 3 (SP03). For assistance in performing the downgrade, or for requesting patch availability, please open a service request with IBM Technical support for the AIX operating system.

A hibára nyitották a IV07564-es APAR-t. A probléma jelenleg vele csupán annyi, hogy még nincs kiadva a javítás 5.3 alá (6.1 alatt a TL06 SP05 már tartalmazza a javítást), azt majd a TL12 Sp05-ben tervezik mellékelni.. Addig is az alábbi oldalon fel lehet iratkozni a SPAM listára, ha esetleg valaki tudni szeretné mikor is lehetne uprgade-elni szeretett AIX-ét (Note: IBM ID kell hozzá):
https://www-304.ibm.com/support/entdocview.wss?uid=isg1IV07564

2011. augusztus 9., kedd

VirtualBox - hogy én mennyire szeretlek

Új ötlettől vezérelve úgy gondoltam, hogy felrakom a Linux (Ubuntu 10.04 LTS) alá a legújabb virtualbox-ot (4.1 build 73209),aztán abban meg majd futtattatok jó kis VM-eket, amiken meg kényem-kedvem szerint kísérletezgethetek. Mivel a kernel egy 2.6.38-10es PAE kernel volt (32 bit), így az OSE verzió már nem tudott felmenni (az még mindig csak 3.1-es, az meg ezzel a kernellel nem kompatibilis), ergo mentem a szokásos úton: A virtualbox.org-ról letöltöttem a 10.04-hez való 32 bites .deb-et, feltettem, majd elkezdtem játszadozni a virutális gépekkel.

Nem is volt ez gond egészen addig, amíg úgy nem gondoltam, hogy mára elég is lesz, sleep-eljük le a notit, aztán menjünk haza -> Itt ugyan is úgy gondolta a gépem, hogy ő nem megy el aludni, helyette dob egy kernel panic-ot.. Na gondoltam szupi, a legtöbb adat hála az égnek mentve van, szóval majd otthon megnézem, addig is full kikapcs.
Itthon aztán elkezdtem nézegetni, hogy ki és hogy, majd kb fél órás bug vadászat és tesztelgetés után kijött, hogy a probléma bizony a vboxdrv modul körül forog: Amennyiben a modul aktív a sleep pillanatában, úgy a kernel dob egy hátast.

Így első gondolatom az volt, hogy semmi gond, fogom magam és szimplán kilapátolom a modulok közül a Virtualboxos modulokat, amikor meg visszajön akkor visszatöltetem.. Ezt kb a következő módon követtem el:
A /etc/pm/sleep.d alatt létrehoztam egy 12virtualbox file-t a következő tartalommal:
#!/bin/bash
case "$1" in
	hibernate|suspend)
		for i in vboxpci vboxnetadp vboxnetflt vboxdrv; do rmmod $i;done
		;;
	thaw|resume)
		for i in vboxdrv vboxpci vboxnetadp vboxnetflt;do modprobe $i;done
		sleep 1
		;;
	*)
		;;
esac
Tesztelés, és lám - így tényleg megy is a játék.. A probléma ezzel a megoldással viszont az, hogy amennyiben fut egy virtuális gép, úgy a gép -persze hogy- nem bírja kilőni a modulokat, úgy hogy ebben az esetben még mindig gáz van.. Szóval goto #dolgozoasztal...
Kis keresés után bele is botlottam az alábbi szálba: http://www.virtualbox.org/ticket/9305
Itt egész szépen ecsetelik is, hogy ez bizony tényleg a 4.1-nek a hülyesége, sőt a végén még oda is biggyesztik, hogy Jul. 28-al commitálták is a változást, és hogy a következő release-ekben ez bent is lesz.. Szupi.. Csak hogy az a release még sehol nem jött ki, szóval innentől vagy "csináld magad", vagy várj.. Én az előbbi mellett döntöttem, így az alábbi játékot játszottam el:
sudo su -
cd /usr/share/virtualbox/src/vboxhost/vboxdrv
wget http://sources.gentoo.org/cgi-bin/viewvc.cgi/gentoo-x86/app-emulation/virtualbox-modules/files/virtualbox-modules-4.1.0-vboxbug9305.patch
patch -p1 < virtualbox-modules-4.1.0-vboxbug9305.patch 
/etc/init.d/vboxdrv setup
ls -l /lib/modules/$(uname -r)updates/dkms/vboxdrv.ko

Ez után jött egy újabb sleep teszt, és láss csodát - így már futó VM esetén is szépen le tud sleepelni a gép... Öröm és bóduttá... Az viszont biztos, hogy most egy jó ideig nem akarok vbox-ot frissíteni, hacsak valami tényleg nem indokolja azt meg..