HACMP failover issue - Unable to unmount the filesystem

Az ember egy idő után már hajlamos azt hiszi, hogy azért nem lehet könnyen meglepni, ha már egy csomó szívást átélt, meg már a kdb-s bugyrokat is megjárta.. Hiába tudjuk, hogy Murphy csak az ilyen jelekre vár, mindig azt hisszük, hogy fel tudjuk venni vele a kesztyűt.. Aztán az ember szembe kap egy általánosnak tűnő problémát, elkezdi a saját kis módján investigálni, majd akkor koppan amikor rájön, hogy valami mégse úgy megy ahogy kéne, vagy valami még így is van amire nem gondolt előzőleg.

Ez se volt most másként.. Felhívtak kollégák, hogy lenne egy HACMP failover probléma: Szegény RG nem tud átállni, és meg kéne már nézni, hogy mi a rákért nem..
Hát jó.. hacmp.out túrás , és elég gyorsan szembejön az első gyanús jel:

***************************
Nov 3 2012 19:42:13 !!!!!!!!!! ERROR !!!!!!!!!!
***************************
Nov 3 2012 19:42:13 cl_deactivate_vgs: Failed varyoff of appvg.

Aham.. na jó.. nézzük mi van még itt, ami miatt ez előjöhetett:

+app_rg:cl_deactivate_vgs(5.910):appvg[vgs_varyoff+282] varyoffvg appvg
0516-012 lvaryoffvg: Logical volume must be closed.  If the logical
        volume contains a filesystem, the umount command will close
        the LV device.
0516-942 varyoffvg: Unable to vary off volume group appvg.

Ahh.. haladunk.. Mi törpént az FS-el?

+app_rg:cl_deactivate_fs(.160)[fs_umount+58] umount /var/mqm/RGmount
umount: error unmounting /dev/RG_LV: Device busy
+app_rg:cl_deactivate_fs(2.160)[fs_umount+66] : At this point, unmount of /var/mqm/RGmount has not worked. So,
+app_rg:cl_deactivate_fs(2.160)[fs_umount+67] : Send a SIGKILL to all processes having open file
+app_rg:cl_deactivate_fs(2.160)[fs_umount+68] : descriptors within this logical volume to allow
+app_rg:cl_deactivate_fs(2.160)[fs_umount+69] : the umount to succeed.
+app_rg:cl_deactivate_fs(2.160)[fs_umount+71] date '+%h %d %H:%M:%S.000'
Nov 03 19:38:46.000
+app_rg:cl_deactivate_fs(2.160)[fs_umount+72] fuser -k -u -x /dev/RG_LV
/dev/RG_LV:   782460(wasRGuser)  782460(wasRGuser)  868596(wasRGuser)  868596(wasRGuser)  938078(wasRGuser)  938078(wasRGuser) 1081448(wasRGuser) 1081448(wasRGuser)
+app_rg:cl_deactivate_fs(2.740)[fs_umount+73] fuser -c -k -u -x /var/mqm/RGmount
/var/mqm/RGmount:
+app_rg:cl_deactivate_fs(3.260)[fs_umount+74] date '+%h %d %H:%M:%S.000'
Nov 03 19:38:47.000
+app_rg:cl_deactivate_fs(3.260)[fs_umount+77] : Wait 2 seconds for the kills to be effective
+app_rg:cl_deactivate_fs(3.260)[fs_umount+79] sleep 2
+app_rg:cl_deactivate_fs(5.260)[fs_umount+82] : Unmount of /var/mqm/RGmount failed. If the force option can be used, try it here.
+app_rg:cl_deactivate_fs(5.260)[fs_umount+84] [[ -n '' ]]
+app_rg:cl_deactivate_fs(5.260)[fs_umount+99] (( 0 == 57 ))
+app_rg:cl_deactivate_fs(5.260)[fs_umount+123] (( 0 == 60 ))
+app_rg:cl_deactivate_fs(5.260)[fs_umount+52] ((count++ ))
+app_rg:cl_deactivate_fs(5.260)[fs_umount+52] (( count <= 60))
+app_rg:cl_deactivate_fs(5.260)[fs_umount+55] : Try to unmount the file system
+app_rg:cl_deactivate_fs(5.270)[fs_umount+56] date '+%h %d %H:%M:%S.000'
+app_rg:cl_deactivate_fs(5.270)[fs_umount+56] : Attempt 2 of 61 to unmount at Nov 03 19:38:49.000
+app_rg:cl_deactivate_fs(5.270)[fs_umount+58] umount /var/mqm/RGmount
umount: error unmounting /dev/RG_LV: Device busy.

Ez a fázis már az application stop után van, ergo a HACMP joggal van felháborodva, hogy miért nem szabad már a device, ha ő azt át akarja adni a másik node-na.. Sebaj, 5.3 óta fel van készítve a HA erre is, gyenge fuser -kux az LV-re megoldja.. fuser -ckux után látszik, hogy tényleg nem maradt process ami használná az FS-t, úgy hogy semmi gáz, mehet az umount..
De álj.. Megint device busy?? Na innen indul a vicces rész.. Főleg amikor az ember eljut a logban eddig:

+app_rg:cl_deactivate_fs(194.630)[fs_umount+56] : Attempt 61 of 61 to unmount at Nov 03 19:41:58.000
+app_rg:cl_deactivate_fs(194.630)[fs_umount+58] umount /var/mqm/RGmount
umount: error unmounting /dev/RG_LV: Device busy
+app_rg:cl_deactivate_fs(194.760)[fs_umount+66] : At this point, unmount of /var/mqm/RGmount has not worked. So,
+app_rg:cl_deactivate_fs(194.760)[fs_umount+67] : Send a SIGKILL to all processes having open file
+app_rg:cl_deactivate_fs(194.760)[fs_umount+68] : descriptors within this logical volume to allow
+app_rg:cl_deactivate_fs(194.760)[fs_umount+69] : the umount to succeed.
+app_rg:cl_deactivate_fs(194.760)[fs_umount+71] date '+%h %d %H:%M:%S.000'
Nov 03 19:41:58.000
+app_rg:cl_deactivate_fs(194.770)[fs_umount+72] fuser -k -u -x /dev/RG_LV
/dev/RG_LV:
+app_rg:cl_deactivate_fs(195.300)[fs_umount+73] fuser -c -k -u -x /var/mqm/RGmount
/var/mqm/RGmount:
+app_rg:cl_deactivate_fs(195.810)[fs_umount+74] date '+%h %d %H:%M:%S.000'
Nov 03 19:41:59.000
+app_rg:cl_deactivate_fs(195.810)[fs_umount+77] : Wait 2 seconds for the kills to be effective
+app_rg:cl_deactivate_fs(195.810)[fs_umount+79] sleep 2
+app_rg:cl_deactivate_fs(197.810)[fs_umount+82] : Unmount of /var/mqm/RGmount failed. If the force option can be used, try it here.
+app_rg:cl_deactivate_fs(197.810)[fs_umount+84] [[ -n '' ]]
+app_rg:cl_deactivate_fs(197.810)[fs_umount+99] (( 60 == 57 ))
+app_rg:cl_deactivate_fs(197.810)[fs_umount+123] (( 60 == 60 ))
+app_rg:cl_deactivate_fs(197.810)[fs_umount+126] : Out of retries to unmount /var/mqm/RGmount. Game over, man, game over.
+app_rg:cl_deactivate_fs(197.810)[fs_umount+128] cl_echo 25 'cl_deactivate_fs: Failed umount of /var/mqm/RGmount.\n' cl_deactivate_fs /var/mqm/RGmount

A "Game over, man, game over" kedves kis üzenet a fejlesztőktől, és meg meg is mosolyogtatna ha nem látnám, hogy szegény HA-m 61x próbálta meg lenyomni a szerencsétlen FS-t de mind végig Device busy-t kapott.

OS oldalról elnézve az FS valóban ott van a mount alatt, és ha én akarom leszedni akkor ugyan azt kapom:

server@root:/ # mount |grep RGmount
         /dev/RG_LV     /var/mqm/RGmount   jfs2   Nov 03 19:22 rw,log=INLINE
server@root:/ # fuser -cux /dev/RG_LV
server@root:/ # umount /var/mqm/RGmount
umount: 0506-349 Cannot unmount /dev/RG_LV: The requested resource is busy.

Na akkor áljunk meg itt picit.. Mi az amit érdemes megnézni ilyenkor?
- Használja e valami az FS-t

- Megtettem, nem dobott semmit..

- Haszmálja e az LV-t valami?

- Ez az amit a HACMP is megnézett, és aminek amúgy több értelme is van, mint az FS-t nézni -> van 1-2 olyan parancs ami az LV-ket cseszteti direktben, ergo ha a /dev/LV-re ráengedünk egy fuser-t akkor azokat is meg tudjuk fogni.. A HA 1x ezeket le is gyilkolta, viszont utána már nem talált semmit

- Nincs e submount az adott FS alatt

- Amennyiben egy másik FS van a lemountolandó alá felhúzva, úgy persze, hogy a kernel nem engedi nekünk az umountot (Ilyenkor a submountot kell első körben leszedni). Ezt könnyen ellenőrizhetjük is a mount paranccsal, de itt sajna ez se játszik, mivel nem volt egy submount se

- AIO/CIO használatban van?

- Ezen a rendszeren konkrétan pont egyik sincs, viszont ezek is képesek ilyen szintű lockokat összehozni. Viszont a HA épp ezért is próbálkozik 61x (ami itt közel 3 percig ment is), hogy az ilyen dolgokkal se legyen gáz, ha ne adj isten az AIO/CIO nem volt elég gyors adott pillanatban. Mint látható ez itt szintén nem jött be.

- Named Pipe?

- Egzotikum, viszont nem szabad figyelmen kívül hagyni.. Alapvetően Inter-process communication célokra szolgál olyan esetekben ahol a jogosultság szeparáció nem teszi lehetővé a normális IPC kommunikációt direkt memórián keresztül (Hozzáteszem, hogy ez inkább a régebbi appoknál bevett eljárá. Az AIX jó ideje tud direktben memóriában adatot átadni különböző jogosultsági szinteken futó alkalmazásoknak Shared Memory-n keresztül (szintén az IPC része). Ilyen esetekben az applikáció képes egy ilyen "pipe" file-t létrehozni, és sima chmod-os/ACL-es megoldással másik user alatt futó applikációnak átadni az adatot direktben. A probléma ezekkel viszont annyi, hogy nincs tényleges file írás/olvasás, mivel az egész hóbelebancot az AIX memórián belül képes lezongorázni, így meg a fuser se veszi észre, hogy a háttérben szopatják a népet, mivel az fopen/fwrite/fclose és hasonló eventekre figyel főként.

Persze kérdés, hogy hogy járunk ezeknek utána.

- Egyik módszer a http://p1ngw1n.blogspot.hu/2012/02/fuser-nemileg-maskent.html-ban felvázolt módszer

- Másik meg az lsof :)

Mivel az első módszert anno már lefedtem, így maradjunk az egyszerűbbnél, és nézzük, hogy az lsof-el mit is látunk ilyenkor :)

server@root:/ # lsof |grep /var/mqm/RGmount
runmqlsr_  933958 wasRGuser    6u  unix              35,13                0t0 5255524237690535936 /var/mqm/RGmount/qmgrs/APILOT!PRT!QMGR/@qmpersist/spipe/ccc.933958
runmqlsr_  933958 wasRGuser    9u  unix 0xf100020000837c08             0t1728                     /var/mqm/RGmount/qmgrs/APILOT!PRT!QMGR/@qmpersist/spipe/pmpipe
runmqlsr_  933958 wasRGuser   12u  unix 0xf100020000736408             0t1852                     /var/mqm/RGmount/qmgrs/APILOT!PRT!QMGR/@qmpersist/spipe/pmpipe
amqzmgr0  1093830 wasRGuser    8u  unix              35,13                0t0 5255524237690535936 /var/mqm/RGmount/qmgrs/MQRG/@qmpersist/spipe/pmpipe
amqzmgr0  1200368 wasRGuser    8u  unix              35,13                0t0 5255524237690535936 /var/mqm/RGmount/qmgrs/APILOT!PRT!QMGR/@qmpersist/spipe/pmpipe
runmqlsr_ 1605678 wasRGuser    6u  unix              35,13                0t0 5255524237690535936 /var/mqm/RGmount/qmgrs/MQRG/@qmpersist/spipe/ccc.1605678
runmqlsr_ 1605678 wasRGuser    9u  unix 0xf100020002275408             0t1728                     /var/mqm/RGmount/qmgrs/MQRG/@qmpersist/spipe/pmpipe
runmqlsr_ 1605678 wasRGuser   12u  unix 0xf100020001ee7808             0t1852                     /var/mqm/RGmount/qmgrs/MQRG/@qmpersist/spipe/pmpipe

BINGO.. Innen már akkor csak akkor gyilkolásznunk kell :)

server@root:/ # kill -9 933958 1093830 1200368 1605678
server@root:/ # umount /var/mqm/RGmount
server@root:/ #

Innen pedig tovább lehet akkor lökni a HA-t is a túloldalra

A történet tanulsága:
- lusta embereknek kötelező az lsof (az experteknek meg a kdb :))
- A HACMP (attól függetlenül, hogy az idők során szinte mindenre próbálták felkészíteni) se tud mindent lekezelni
- A fejlesztőknek is van humora :)
- Murphy lehet, hogy köcsög mindig, de valahogy még is az ilyen szívásokkal tanulja meg az ember, hogy mennyire is halandó, és lényegében így tanulja csak meg azokat a leckéket, amikre más nem lenne képes megtanítani (se iskola, se oktatás, se certifikációk)

EPIC moments - Avagy miért születetthetett meg a pokoli operátor?

Az ember néha tényleg azt hinné, hogy a hülyeségnek azért valahol csak van határa, de időről időre rá kell döbbenjek, hogy az ami még tegnap tényleg jó viccnek tűnt, ma már lehet komor valóságként materializálódik a szemem előtt.

Álljon hát itt néhány kis szösszenet azokból az "URAM ISTEN" pillanatokból, amiket az elmúlt időszakban sikerült megtapasztalnom.

1) - "Van e elég hely a /dev/null alatt?"

Anno volt ez egy elszólása egy némileg távoli kollégámnak, amin sikerült jót vigadni. A dolog apropója annyi volt, hogy az egyik logfile-t átirányítottuk a /dev/null alá (mondván, hogy úgy se használjuk, csak ha debugolni kell) erre ő -féltve, hogy az FS megtelik- megkérdezte, hogy van e elég hely alatta.. Ez anno tényleg vicces volt, viszont amikor az ember ilyet lát, de most már kezdem azt hinni, hogy ilyen felszólalásokat Murphy felhívásnak érzi, hogy megcáfolja őket ; főleg amikor ilyesmi issue jön az emberrel szembe:

server@root:/ # df -m /
Filesystem    MB blocks      Free %Used    Iused %Iused Mounted on
/dev/hd4         192.00      0.00  100%     3694    85% /
server@root:/ # du -axk / |sort -rn |head -5
193860  /
109992  /dev
109956  /dev/null
27160   /etc
24272   /lpp
server@root:/ # ls -l /dev/null
-rw-------    1 root     system    112590848 Aug 23 19:55 /dev/null
server@root:/ # du -m /dev/null
107.38  /dev/null
server@root:/ # file /dev/null
/dev/null: commands text

Hogy az a jó élet.. WTF?? A /dev/null nem egy character file-nak kéne lennie? Dehogynem.. Akkor miért nem az?? A válasz: Mert valaki letörölte.. Az első jött ment process meg nyomban létre is hozta a file-t egy átirányítás révén ($command 2>/dev/null - szerintem mindenki látott már hasonlót :)), ami aztán lassan meg is telítette a / filerendszert..

* facepalm * ... Aztán akkor meg a gyógyszer:

rm /dev/null; mknod /dev/null c 2 2; chmod 666 /dev/null

Ha azt hiszitek, itt vége a sztorinak tévedtek!! Murphy úgy gondolta, hogy lesz 2. felvonás is:

server@root:/ # ls -l /dev/null*
crw-rw-rw-    1 root     system        2,  2 Aug 23 15:09 /dev/null
-rw-r--r--    1 root     system     20057274 Aug 23 13:54 /dev/null 2>&1

*sigh* Ez meg mi a lóturó...

Kis turkálás, majd az oka is megvan: http://www-01.ibm.com/support/docview.wss?uid=nas74d33539b559cc0308625792900533a8f
Igen.. A programozók ilyet is tudnak...

2) - Forkbomb sudo-val

A szituáció a következő: Megpróbálsz belépni a rendszerre, de a belépés sikertelen. HMC-ről látod, hogy a gép megy, de a gépet a virtuális terminálon át se sikerül elérni (a terminál megnyílik, de login screen-t nem kapsz). A gép lényegében vegetál, úgy hogy nincs más mint előre - force restart HMC-ről. A gép vissza is jön az életbe, persze az okot ekkor még nem tudjuk, tehát elkezdünk nézegelődni a logokban, hogy mi a fene van.. Rövid vizsgálódás után a shell közli velem, hogy "unable to fork"..
Őőő... Mi van??? És a gép tényleg ismét elkezdi azt amit előtte is: nem lehet vele semmit se kezdeni..
Újabb újraindítás, svmon-al nézzük, hogy mi zabálja a memóriát, de semmi különöset nem látok.. topas.. detto semmi.. ps lista.... állj..

server@user:/ # ps -ef
     UID      PID     PPID   C    STIME    TTY  TIME CMD
    root        1        0   0   Jul 05      -  0:06 /etc/init
    root  1441896        1   0   Jul 05      - 21:51 /usr/sbin/syncd 60
    root  1638488        1   0   Jul 05      -  0:00 /usr/ccs/bin/shlap64
    root  1769656        1   0   Jul 05      -  0:00 /usr/lib/errdemon
    root  2359508  8192170   0 17:57:36  pts/0  0:00 -ksh
    root  2424966  3145848   0   Jul 05      -  0:00 /usr/sbin/biod 6
    root  2556062  3145848   0   Jul 05      -  0:01 /usr/sbin/hostmibd
    root  2752642  3145848   0   Jul 05      -  0:02 /usr/sbin/syslogd
    root  2818192  3145848   0   Jul 05      -  1:35 sendmail: accepting connections
    root  2883696  3145848   0   Jul 05      -  0:02 /usr/sbin/snmpmibd
    root  2949226  3145848   0   Jul 05      -  0:26 /usr/sbin/aixmibd
    root  3014786 15335476   0 17:57:32  pts/0  0:00 -ksh
    root  3080398  4391120   0 17:57:29  pts/0  0:00 -ksh
    root  3145848        1   0   Jul 05      -  0:00 /usr/sbin/srcmstr
    root  3211378  3145848   0   Jul 05      -  0:00 /usr/sbin/snmpd
    root  3342544  4194544   0 17:57:33  pts/0  0:00 -ksh
    root  3407976  3145848   0   Jul 05      -  0:00 /usr/sbin/portmap
    root  3473514  3145848   0   Jul 05      -  0:00 /usr/sbin/inetd
    root  3539066  7864376   0 17:57:32  pts/0  0:00 -ksh
    root  3604658 10420352   0 17:57:33  pts/0  0:00 -ksh
    root  3735804  7536670   0 17:57:34  pts/0  0:00 -ksh
    root  3801268  7340182   0 17:57:32  pts/0  0:00 -ksh
    root  3866832  9044146   0 17:57:31  pts/0  0:00 -ksh
    root  3932166  7667938   0 17:57:34  pts/0  0:00 -ksh
    root  3997750  9764978   0 17:57:30  pts/0  0:00 -ksh
    root  4063286  4259944   0 17:57:31  pts/0  0:00 -ksh
    root  4128854 12910818   0 17:57:34  pts/0  0:00 -ksh
    root  4194544 12320872   0 17:57:33  pts/0  0:00 -ksh
    root  4259944  8978666   0 17:57:31  pts/0  0:00 -ksh
    root  4325470 13041670   0 17:57:35  pts/0  0:00 -ksh
    root  4391120 10223744   0 17:57:29  pts/0  0:00 -ksh
    root  4456662  3604658   0 17:57:34  pts/0  0:00 -ksh
...
    root 15335476 11337968   0 17:57:32  pts/0  0:00 -ksh
    root 15401026 12648676   0 17:57:36  pts/0  0:00 -ksh
    root 15532266 15204356   0 17:57:37  pts/0  0:00 -ksh
server@user:/ # ps -ef |grep -c ksh
245

őő.. ez kicsit sok nem?? Plusz mi a fenétől jöttek ezek elő??? Közben persze telik az idő, és ismét beüt a krach ; újabb restart, de most már sejtem, hogy mi a probléma , valamiért túl sok ksh forkolódik és sok kicsi sokra megy alapon mindegyik lefoglal magának egy kis memóriát, ami azért ekkora léptékben már képes megzabálni a gépet.. Úgy hogy az újraindítás után nyomban proctree-vel kezdem a játékot, s mit látok?

server@user:/ # ps -ef |grep ksh |tail -1
    root 1478878 1466588   0 18:20:10  pts/0  0:00 -ksh
server@user:/ # proctree 1478878
434214    /bin/ksh /etc/rc.itm1
   389164    -ksh -c /opt/IBM/ITM/bin/itmcmd agent start ul >/dev/null 2>&1
      462944    -ksh
         385246    -ksh
            405732    -ksh
               176296    -ksh
                  442614    -ksh
                     381148    -ksh
                        94260    -ksh

És innen meg végtelen sorokban ksh hegyek..

Na nézzük mi jön le ebből: Van egy 434214 PID-ű process-ünk ami épp egy ITM6-os indító script, ami meghívja az UL agent startupját, ami meg aztán hegyekben szórja a ksh-s forkokat.. Ahogy a hívásból látjuk egy ksh futtatja magában a /opt/IBM/ITM/bin/itmcmd file-t is (ergo az is script), ami meg init-ből indul..
Scriptet megnéztem - semmi különös - a szokásos hívások vannak csak benne.. Fejvakarás, wattafák.. Majd megpróbálok én is felmenni root szintre sudo-val, és furcsa módon tapasztalom, hogy bizony, shell-t azt nem kapok... Ctrl+C hegyekben, aztán csak kaptam shell-t..
Ez volt az a pillanat amikor már kezdtem azt hinni, hogy a root user-el van csak gond ( a user shellem gond nélkül ment), ergo belekukkantottam a root profile file-jába, és ezt a gyönyörűséget láttam:

server@root:/ # cat .profile
export ENV=.kshrc
# Define initial prompt to include hostname
export PS1=`hostname`@$USER':$PWD # '
sudo su -

ŐŐ.. Álj.. 'sudo su -' a root profiljában???? KI VOLT AZ A MARHA???? Profil átír, 'sudo su -' sor eltávolít, rendszer ujraindít, minden működik szépen.

Na de mi is történt? - valamelyik ökör belerakta a root profiljába a 'sudo su -' sort.. Miért is gond ez? Mert a 'sudo su -' a root user alatt kérdés (meg jelszó kérés) nélkül lefut, és egy újabb shell-t nyit, ami meg megint beolvassa a root .profile-ját, ami így megint lefuttatja a 'sudo su -'-t és így tovább amíg a szerver bírta...
Ergo valaki ügyesen fork bomb-á alakította a sudo-t root alatt :)

3) - Az öngyilkos java alkalmazás

Anno még írtam is az egyik szép kis kamikáze kódról, ami sikeresen szembe jött velem.. Most újra elő kell vegyem a témát, mert az amit láttam az nem hogy ennek egy emeltebb formája volt, mintsem egy komplett seppuku :)
Na szóval... Van egy szerver, egy rajta futó Websphere (Web's Fear) alkalmazással rajta, amin belül meg fut egy valaki által írt applikáció jópár éve..
Egyik nap megszólal a vészharang, ügyfél sikoltozik, hogy a hőn szeretett alkalmazása nem működik.. Jó, rendben nézzünk utána.. Kis nyomozás, közös munka az application support group-al, majd kiderül, hogy hiányzik az alkalmazás "magja". Pontosabban ott van, csak nem úgy működik, ahogy kéne (azaz sehogy).
Az elején még nem értettem miről van szó, de aztán lassacsakán megvilágosodtam.. Íme egy röpke összefoglaló arról, hogy mi történt (időrendi sorrendben)
- Jópár éve már, hogy valami fejlesztő palánta megírta az alkalmazás core modulját
- Ez a modul jópár évig gond nélkül, aztán beütött a krach - Az applikáció összeomlott, majd nem volt képes újraindulni.
- Az applikáció HOME könyvtárában lévő core file elemzése után kiderült, hogy az alkalmazás egy verem hiba miatt esett össze, majd a szokásos módon dobott egy java core-t. Mindezt egy olyan applikációs almodul játszotta el, amit közvetlenül a fő mag hívott
- Aki még nem találta ki, annak itt a csattanó - Igen, az applikáció magját 'core'-nak hívták.. Ezt volt a file neve..

Tehát mi is történt: Volt egy core nevű alkalmazásunk, ami szépen futott, míg az egyik almodulja (ugyan abból a HOME-ból futtatva) nem dobott egy coredumpot, ezzel szimplán felülvágva az eredeti 'core' file-t, innentől meg az alkalmazás központi magja nem volt elérhető, ergo persze, hogy nem is indult el ez után.

És egyesek még csodálkoznak, hogy az IT-sok néha "kicsit" idegesek.. El nem tudom képzelni miért..

AIX - booby trap

Az ember azt hinné, hogy az AIX-el nem lehet vicces dolgokat csinálni, de olykor olykor kellemesen tud csalódni abban amit el lehet ténylegesen érni vele.
Múltkor például sikerült rájönnöm, hogy IPsec-el lehet olyan szabályt létrehozni, ami annyit csinál, hogy ha egy kliens megpróbál az adott portra csatlakozni, akkor kap egy X sec-es ban-t mindenféle hálózati forgalommal együtt..
Belegondolva ez egy standard támadó ellen teljesen jó kis csapda -> Csupán annyit kell csinálnunk, hogy egy meglehetősen alacsony portra kirakunk egy sérülékeny szolgáltatást (rsh, telnet, csak hogy finoman is nézzen ki), majd rádefiniálunk egy szabályt, hogy aki megpróbál bejönni, annak mondjuk 1 napig csend legyen.. Amennyiben a támadónk valamiféle scanneléssel próbálkozik (sima nmap is elég :)) már bele is esett a csapdába.. Csodálatos, mit ne mondjak :))

Hogy ez a valóságban hogy is néz ki? Nos van 1-2 alapfeltétel:
- clic.rte alatti csomagoknak fent kell legyenek a gépen
- Be kell legyen töltve az Ipsec modul (ipsec_v4, ha IPv4et akarunk védeni)
- A szabályokat nekünk kell beállítani.

Tehát a feladat szimplán ennyi:

server # installp -avXYgd /source clic.rte.lib clic.rte.kernext  
    # Alap csomagok telepítése
server # smitty ips4_start # Indítsuk el az Ipsec IPv4es támogatását
server # lsdev -l ipsec_v4 # Nézzük meg elérhetővé vált e az ipsec_v4 device
ipsec_v4 Available  IP Version 4 Security Extension

A szabály beállítás némileg macerásabb. Csinálhatjuk 'smitty ips4_add_filter'-el, vagy genfilt-en keresztül parancssorból is.

Smitty-ből így néz ki a konfigolás:
* Rule Action                                                                   [shunHost]            
* IP Source Address                                                         [0.0.0.0]
* IP Source Mask                                                             [0.0.0.0]
  IP Destination Address                                                   [10.1.0.100]
  IP Destination Mask                                                       []
* Apply to Source Routing? (PERMIT/inbound only)    [yes]                 
* Protocol                                                                         [all]                 
* Source Port / ICMP Type Operation                             [any]                 
* Source Port Number / ICMP Type                                [0]                   
* Destination Port / ICMP Code Operation                     [eq]                  
* Destination Port Number / ICMP Type                        [23]                  
* Routing                                                                         [both]                
* Direction                                                                       [inbound]             
* Log Control                                                                  [yes]                 
* Fragmentation Control                                                 [0]                   
* Interface                                                                       [all]                 
  Expiration Time (sec)                                                   [300]                 
  Pattern Type                                                                 [none]                
  Pattern / Pattern File                                                     []
  Description                                                                   [telnet_boobytrap]

Ugyan ez parancssorból:

server # genfilt -v 4 -a H -s '0.0.0.0' -m '0.0.0.0' -d 10.1.0.100 -g y -c all -o any -p 0 -O eq -P 23 -r B -w I -l Y -t 0 -i all -e 300 -D 'telnet_boobytrap'

Némi kis magyarázat a kapcsolókról:
-v 4 -> IP version 4
-a H -> ShunHost
-s 0.0.0.0 -> Source address (0.0.0.0 == bárhonnét)
-m 0.0.0.0 -> Source Mask (0.0.0.0 == mindenhonnan)
-d 10.1.0.100 -> Destination IP (nem kötelező, de a tapasztalatok alapján érdemes megadni, mert nélküle mintha nem menne (nem tudtam rájönni miért))
-g y -> Source packet átroute-olása
-c all -> Minden protokolon (udp/tcp/icmp/ospf/ipip/esp/ah)
-o any -> Source port (0 == bármelyik)
-p 0 -> Source port (0 == bármelyik)
-O eq -> Milyen tipusú operátort használjuk (eq == equal -> megyegező port)
-P 23 -> Port száma (23 == telnet)
-r B -> Routing-ot pontosan mely láncokra érvényesítsük (route forward, local routing, avagy mind2 (both)
-w I -> Direction. Jelen esetben csak a bejövő csomagokkal foglalkozunk
-l Y -> Loggolás.. Persze, hogy akarunk loggolni :) (For the record - a logok a local4:err, local4:info és local4:notice alá mennek)
-t 0 -> Fragmenation Control, avagy melyik ID-jű tunnelbe toljuk majd bele a csomagot ( a 0 default)
-i all -> Interface.. Mindenhol halgatózni akarunk természetesen :)
-e 300 -> Expiration time másodpercben (kíméletesek leszünk, most csak 5 perces bann jár :))
-D 'telnet_boobytrap' -> Description.. Hogy kb a leírás alapján tudjuk mit is akarhatott a költő amikor ezt a szabályt létrehozta..

Ennek az eredménye egy olyan rule lesz, ami bárhonnét jövő IPv4-es kapcsolatot kitilt 5 percre, ha én a 23-as portra próbálok csatlakozni.
Szerverről lekérve pedig láthatjuk is a kis szabályunkat:

server # lsfilt -v4 -O
1|permit|0.0.0.0|0.0.0.0|0.0.0.0|0.0.0.0|no|udp|eq|4001|eq|4001|both|both|no|all packets|0|all|0|||Default Rule
2|*** Dynamic filter placement rule for IKE tunnels ***|no
3|shunHost|0.0.0.0|0.0.0.0|0.0.0.0|255.255.255.255|yes|all|any|0|eq|23|both|inbound|yes|all packets|0|all|300|||telnet_boobytrap
0|permit|0.0.0.0|0.0.0.0|0.0.0.0|0.0.0.0|yes|all|any|0|any|0|both|both|no|all packets|0|all|0|||Default Rule

Na most azért van itt még 1-2 dolgot amire ki kell térni:
- A 0ás,1es,2es szabályok állandóak, ergo a legkisebb ID amit kaphatunk az 3as lesz 1 szabályhoz, illetve afölött
- Azzal, hogy a rule-t létrehoztuk még nem jelenti, hogy életbe is léptettük azonnal -> azt külön meg kell tenni :)
- Ráadásként a loggolást is hiába állítottuk be, ha nem engedélyezzük azt is :)

Mázlinkra ez összesen 2 új parancsot jelent:

server # mkfilt -v4 -g start  # Loggolás aktiválása
server # mkfilt -v4 -u    # A felvitt rule-ok aktiválása

Innentől fogva viszont életbe léptek a változtatásaink, és mindenféle bajkeverő ilyen következményekkel kell szembenézzen

Mit jelent ez a gyakorlatban?
"telnet_boobytrap" szabály nélkül az nmap ezt dobja vissza:

pentester # nmap -sS 10.1.0.100

Starting Nmap 5.51 ( http://nmap.org ) at 2012-07-25 22:15 Central Europe Daylight Time
Nmap scan report for 10.1.0.100
Host is up (0.061s latency).
Not shown: 994 closed ports
PORT     STATE SERVICE
23/tcp   open  telnet
111/tcp  open  rpcbind
514/tcp  open  shell
1334/tcp open  writesrv
2049/tcp open  nfs
9090/tcp open  zeus-admin
MAC Address: 00:00:00:41:47:4E (Xerox)

Nmap done: 1 IP address (1 host up) scanned in 1.72 seconds

"telnet_boobytrap"-al ugyan ez:

pentester # nmap -sS 10.1.0.100

Starting Nmap 5.51 ( http://nmap.org ) at 2012-07-25 21:46 Central Europe Dayliht Time
Nmap scan report for 10.1.0.100
Host is up (0.063s latency).
Not shown: 919 closed ports, 76 filtered ports
PORT     STATE SERVICE
111/tcp  open  rpcbind
514/tcp  open  shell
1334/tcp open  writesrv
2049/tcp open  nfs
9090/tcp open  zeus-admin
MAC Address: 00:00:00:41:47:4E (Xerox)

Nmap done: 1 IP address (1 host up) scanned in 1521.31 seconds

1.72 sec VS 1521.32 sec (több mint 25 perc :)) és csak egy 5 perces tiltást állítottunk be.. Képzeld el mi lesz ha "kicsit" emeljük a tétet, mondjuk 86400-ra (24 óra) :))

Nézzük mi van akkor ha valaki csak simán be akar telnetelni:

pentester  # telnet 10.1.0.100
Trying...
telnet: connect: A remote host did not respond within the timeout period.

Mindeközben a logban:

server  # tail -f /var/log/syslog.out |grep ipsec
Jul 25 20:29:42 server local4:info ipsec_logd: #:2 R:d  I:10.1.0.100 S:10.1.0.153 D:10.1.0.100 P:tcp/ack SP:53688 DP:23 R:l I:en1 F:n T:0 L:60
Jul 25 20:29:42 server local4:info ipsec_logd: #:1 R:d  O:995:46f4:995:46d2:995:46f4:600:d1b8 S:17:0:0:1::2 D:0:1::656e:3100:f100:500 P:(1) -:54272 -:61696 R:l I: F:n T:3935892 L:18472
Jul 25 20:29:43 server local4:info ipsec_logd: #:0 R:d  I:10.1.0.100 S:10.1.0.153 D:10.1.0.100 P:tcp/ack SP:53688 DP:23 R:l I:en1 F:n T:0 L:60
Jul 25 20:29:43 server local4:info ipsec_logd: #:-2010349502 R:d  O:995:46f4:995:46d2:995:46f4:600:d1b8 S:17:0:0:1:: D:0:1::656e:3100:f100:500 P:ip -:12288 -:61696 R:l I: F:n T:3935892 L:0
Jul 25 20:29:46 server local4:info ipsec_logd: #:0 R:d  I:10.1.0.100 S:10.1.0.153 D:10.1.0.100 P:tcp/ack SP:53688 DP:23 R:l I:en1 F:n T:0 L:60
Jul 25 20:29:46 server local4:info ipsec_logd: #:-2010349502 R:d  O:995:46f4:995:46d2:995:46f4:600:d1b8 S:17:0:0:1:: D:0:1::656e:3100:f100:500 P:ip -:12288 -:61696 R:l I: F:n T:3935892 L:0
Jul 25 20:29:52 server local4:info ipsec_logd: #:0 R:d  I:10.1.0.100 S:10.1.0.153 D:10.1.0.100 P:tcp/ack SP:53688 DP:23 R:l I:en1 F:n T:0 L:60
Jul 25 20:29:52 server local4:info ipsec_logd: #:0 R:d  O:995:46f4:995:46d2:995:46f4:600:d1b8 S:17:0:0:1:: D:0:1::656e:3100:f100:500 P:ip -:27136 -:61696 R:l I: F:n T:3935892 L:0
Jul 25 20:30:04 server local4:info ipsec_logd: #:0 R:d  I:10.1.0.100 S:10.1.0.153 D:10.1.0.100 P:tcp/ack SP:53688 DP:23 R:l I:en1 F:n T:0 L:60
Jul 25 20:30:04 server local4:info ipsec_logd: #:1 R:d  O:995:46f4:995:46d2:995:46f4:600:d1b8 S:17:0:0:1:: D:0:1::656e:3100:f100:500 P:(1) -:9216 -:61696 R:l I: F:n T:3935892 L:0
Jul 25 20:30:28 server local4:info ipsec_logd: #:0 R:d  I:10.1.0.100 S:10.1.0.153 D:10.1.0.100 P:tcp/ack SP:53688 DP:23 R:l I:en1 F:n T:0 L:60
Jul 25 20:30:28 server local4:info ipsec_logd: #:0 R:d  O:995:46f4:995:46d2:995:46f4:600:d1b8 S:17:0:0:1:: D:0:1::656e:3100:f100:500 P:ip -:27136 -:61696 R:l I: F:n T:3935892 L:0
Jul 25 20:30:57 server local4:info ipsec_logd: #:0 R:d  I:10.1.0.100 S:10.1.0.153 D:10.1.0.100 P:tcp/ack SP:53697 DP:23 R:l I:en1 F:n T:0 L:60
Jul 25 20:30:57 server local4:info ipsec_logd: #:-2010349502 R:d  O:995:46f4:995:46d2:995:46f4:600:d1c1 S:17:0:0:1:: D:0:1::656e:3100:f100:500 P:ip -:12288 -:61696 R:l I: F:n T:3935892 L:0
Jul 25 20:30:58 server local4:info ipsec_logd: #:0 R:d  I:10.1.0.100 S:10.1.0.153 D:10.1.0.100 P:tcp/ack SP:53697 DP:23 R:l I:en1 F:n T:0 L:60
Jul 25 20:30:58 server local4:info ipsec_logd: #:0 R:d  O:995:46f4:995:46d2:995:46f4:600:d1c1 S:17:0:0:1:: D:0:1::656e:3100:f100:500 P:ip -:27136 -:61696 R:l I: F:n T:3935892 L:0
Jul 25 20:31:01 server local4:info ipsec_logd: #:0 R:d  I:10.1.0.100 S:10.1.0.153 D:10.1.0.100 P:tcp/ack SP:53697 DP:23 R:l I:en1 F:n T:0 L:60
Jul 25 20:31:01 server local4:info ipsec_logd: #:-2010349502 R:d  O:995:46f4:995:46d2:995:46f4:600:d1c1 S:17:0:0:1:: D:0:1::656e:3100:f100:500 P:ip -:12288 -:61696 R:l I: F:n T:3935892 L:0
Jul 25 20:31:07 server local4:info ipsec_logd: #:0 R:d  I:10.1.0.100 S:10.1.0.153 D:10.1.0.100 P:tcp/ack SP:53697 DP:23 R:l I:en1 F:n T:0 L:60
Jul 25 20:31:07 server local4:info ipsec_logd: #:0 R:d  O:995:46f4:995:46d2:995:46f4:600:d1c1 S:17:0:0:1:: D:0:1::656e:3100:f100:500 P:ip -:27136 -:61696 R:l I: F:n T:3935892 L:0
Jul 25 20:31:19 server local4:info ipsec_logd: #:0 R:d  I:10.1.0.100 S:10.1.0.153 D:10.1.0.100 P:tcp/ack SP:53697 DP:23 R:l I:en1 F:n T:0 L:60
Jul 25 20:31:19 server local4:info ipsec_logd: #:1 R:d  O:995:46f4:995:46d2:995:46f4:600:d1c1 S:17:0:0:1:: D:0:1::656e:3100:f100:500 P:(1) -:9216 -:61696 R:l I: F:n T:3935892 L:0
Jul 25 20:31:43 server local4:info ipsec_logd: #:0 R:d  I:10.1.0.100 S:10.1.0.153 D:10.1.0.100 P:tcp/ack SP:53697 DP:23 R:l I:en1 F:n T:0 L:60
Jul 25 20:31:43 server local4:info ipsec_logd: #:0 R:d  O:995:46f4:995:46d2:995:46f4:600:d1c1 S:17:0:0:1:: D:0:1::656e:3100:f100:500 P:ip -:27136 -:61696 R:l I: F:n T:3935892 L:0

Amire tessék figyelni: Amint az egyik szabály érvényesül egy bejövő címre, az ipsec elkezdi logolni az összes próbálkozását a node-nak, miután ki lett tiltva (az nmap kellemes kis 2 MB-os logot generált nekem a ~25 perc alatt :)) de innentől már nem csak a megadott portra (23), hanem mindre amire a támadó gép bepróbálkozott