[audit] Wyszukiwanie zdarzeń i interpretacja logów audytowych

Red Hat 6.x / CentOS 6.x
System audytowy loguje swoje wiadomości do pliku /var/log/audit/audit.log. Wpisy te zawierają dużo informacji różnego rodzaju i zależnie od typu zdarzenia jakie zaszło w systemie mogą nieznacznie różnić się pomiędzy sobą, dlatego analizowanie samego logu wymaga dokładnego wczytania się w jego treść. System oferuje różnego rodzaju narzędzia raportujące na podstawie tego logu, ale znajomość składni pliku może niekiedy okazać się przydatna.

Typowy wpis w audit.log wygląda podobnie do poniższego:

type=SYSCALL msg=audit(1440437032.702:20): arch=c000003e syscall=1 success=yes exit=1 a0=3 a1=7ffd651b08d0 a2=1 a3=7ffd651af650 items=0 ppid=2583 pid=2800 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts0 ses=1 comm="setenforce" exe="/usr/sbin/setenforce" subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 key=(null)

Możemy w nim wyróżnić kilka charakterystycznych elementów:
* type=SYSCALL to typ wiadomości audytowej. Tutaj akurat wiadomość tyczy się wywołania systemowego, ale typów tych jest wiele.
* msg=audit(1440437032.702:20) zawiera w sobie znacznik czasu oraz ID wiadomości. Znacznik czasu znajduje się przed znakiem dwukropka i wyznacza liczbę sekund "od epoki". Za dwukropkiem znajdziemy ID wiadomości.
Znacznik czasu, jeśli zachodzi taka potrzeba możemy "zdekodować" używając systemowego polecenia date:

[root@ipaclient1 ~]# date --date=@1440437032.702
Mon Aug 24 19:23:52 CEST 2015

* arch to znacznik architektury procesora w notacji hexadecymalnej - c000003e oznacza x86_64
* syscall=1 to typ wywołania systemowego
* success=yes to efekt działania tego wywołania - w naszym wypadku wywołanie zakończyło się sukcesem
* exit=1 to exit code przesłany przez nasze wywołanie
* pola a0 - a3 to pierwsze cztery argumenty danego syscalla w notacji hexadecymalnej
* items=0 informuje nas o ilości wpisów danego typu dla danego eventu
* ppid to Parent Process ID dla procesu wywołującego nasz SYSCALL
* pid to Process ID
* auid to tzw. Audit User ID, czyli oryginalny UID użytkownika który nadawany jest po jego zalogowaniu do systemu i przekazywany do końca sesji
* uid oraz gid to UID iraz GID (group ID) użytkownika, który rozpoczął proces który audytujemy
* euid oraz egid to efektywny user ID oraz group ID
* fsuid oraz fsgid to file system uid i gid
* suid i sgid  pokazują set uid oraz set gid dla procesu
* tty to oczywiście terminal z którego proces rozpoczęto
* ses to ID sesji
* comm="setenforce" to commandline'owa komenda, która została użyta do wywołania naszego procesu
* exe to oczywiście ścieżka do wykonanej binarki
* subj przedstawia nam kontekst selinuxa z jakim analizowany proces się rozpoczął
* key jest definiowanym w regule audytowej kluczem/nazwą danej reguły (bliżej poznamy podczas tworzenia własnych reguł)

Część pól ma oczywiste przełożenie na elementy procesu, więc analiza takiego wpisu nie będzie problemem, poza tym, że ilość danych spowoduje, że czas potrzebny do takiej analizy będzie dość znaczący.

Wyszukiwanie zdarzeń audit - ausearch

Paza zwykłym grepowaniem logu audit.log mamy możliwość przeszukiwania tegoż logu za pomocą narzędzia systemowego o nazwie ausearch. Ma ono taką przewagę nad zwykłym grepem, że potrafi interpretować część pól logu, np. zamieniając uid usera na jego nazwę czy prezentować datę wystąpienia w czytelnym formacie.

Najprzydatniejszymi operatorami komendy są moim zdaniem:
* -i powodujący interpretację pól logu
* -a event_id wyszukujący w logu wpisy dla konkretnego zdarzenia
* -c comm_name  wyszukujący wpisy dla konkretnej komendy commandline'a
* -k klucz wyszukująca po kluczu/nazwie reguły
* -p PID szukająca po PID procesu
* -x /sciezka/do/binariów szukająca zdarzeń generowanych przez konkretne binarium
* -ts [data] [godzina] lub -te [data] [godzina] ograniczające czasowo wyszukiwanie - ts to 'time start', analogicznie te to 'time end'. Przydatne mogą okazać się tu możliwe do użycia słowa kluczowe określające czas. Do wyboru mamy now, recent, today, yesterday, this-week, this-month oraz this-year. Aliasy, poza recent i now to czas zaczynający się 1 sekundę po północy odpowiednio dziś, wczoraj, pierwszego dnia tygodnia (zależnie od ustawień lokalnych), pierwszego dnia miesiąca czy roku. Recent oznacza 10 minut przed aktualną godziną. Oczywiście nic nie stoi na przeszkodzie, aby podać konkretną datę i godzinę (zgodnie z naszym formatem systemowym).

Opcji jest więcej, i naturalnie opisane są w manualu dla ausearch.
Korzystając z przytaczanego wcześniej wpisu sprawdźmy działanie ausearch. Na początek sprawdźmy jakie wpisy znajdziemy dla komendy setenforce:

[root@ipaclient1 ~]# ausearch -i -c setenforce
----
type=SYSCALL msg=audit(08/24/2015 19:23:52.702:20) : arch=x86_64 syscall=write success=yes exit=1 a0=0x3 a1=0x7ffd651b08d0 a2=0x1 a3=0x7ffd651af650 items=0 ppid=2583 pid=2800 auid=root uid=root gid=root euid=root suid=root fsuid=root egid=root sgid=root fsgid=root tty=pts0 ses=1 comm=setenforce exe=/usr/sbin/setenforce subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 key=(null)
type=MAC_STATUS msg=audit(08/24/2015 19:23:52.702:20) : enforcing=0 old_enforcing=1 auid=root ses=1

Możemy też zweryfikować co jeszcze w danym procesie się działo, wyszukując wpisów dotyczących konkretnego ID zdarzenia. Jak wynika z analizy pól logu ID takie znajdziemy w polu msg=audit(1440437032.702:20), i będzie nim wartość widniejąca po dwukropku:

[root@ipaclient1 ~]# ausearch -i -a 20
----
type=SYSCALL msg=audit(08/24/2015 19:23:52.702:20) : arch=x86_64 syscall=write success=yes exit=1 a0=0x3 a1=0x7ffd651b08d0 a2=0x1 a3=0x7ffd651af650 items=0 ppid=2583 pid=2800 auid=root uid=root gid=root euid=root suid=root fsuid=root egid=root sgid=root fsgid=root tty=pts0 ses=1 comm=setenforce exe=/usr/sbin/setenforce subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 key=(null)
type=MAC_STATUS msg=audit(08/24/2015 19:23:52.702:20) : enforcing=0 old_enforcing=1 auid=root ses=1
----
type=CRED_ACQ msg=audit(08/29/2015 14:57:02.602:20) : user pid=2983 uid=root auid=root ses=1 subj=unconfined_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=PAM:setcred acct=root exe=/usr/sbin/sshd hostname=192.168.1.6 addr=192.168.1.6 terminal=ssh res=success'
----
type=CRYPTO_KEY_USER msg=audit(08/31/2015 09:47:39.839:20) : user pid=2090 uid=root auid=root ses=1 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=server fp=97:8b:22:1c:92:9d:f9:b7:b5:96:ee:f2:c5:3b:d5:59 direction=? spid=2090 suid=root  exe=/usr/sbin/sshd hostname=? addr=192.168.1.6 terminal=pts/0 res=success'
----
type=CRYPTO_KEY_USER msg=audit(08/31/2015 09:51:39.095:20) : user pid=2081 uid=root auid=root ses=1 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=server fp=97:8b:22:1c:92:9d:f9:b7:b5:96:ee:f2:c5:3b:d5:59 direction=? spid=2081 suid=root  exe=/usr/sbin/sshd hostname=? addr=192.168.1.6 terminal=pts/0 res=success'
----
type=CRYPTO_KEY_USER msg=audit(08/31/2015 10:34:17.588:20) : user pid=2085 uid=root auid=root ses=1 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=server fp=97:8b:22:1c:92:9d:f9:b7:b5:96:ee:f2:c5:3b:d5:59 direction=? spid=2085 suid=root  exe=/usr/sbin/sshd hostname=? addr=192.168.1.6 terminal=pts/0 res=success'
----
type=CRYPTO_KEY_USER msg=audit(08/31/2015 11:03:31.530:20) : user pid=2090 uid=root auid=root ses=1 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=server fp=97:8b:22:1c:92:9d:f9:b7:b5:96:ee:f2:c5:3b:d5:59 direction=? spid=2090 suid=root  exe=/usr/sbin/sshd hostname=? addr=192.168.1.6 terminal=pts/0 res=success'
----
type=CRYPTO_KEY_USER msg=audit(08/31/2015 20:25:27.072:20) : user pid=2197 uid=root auid=root ses=1 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=server fp=97:8b:22:1c:92:9d:f9:b7:b5:96:ee:f2:c5:3b:d5:59 direction=? spid=2197 suid=root  exe=/usr/sbin/sshd hostname=? addr=192.168.1.6 terminal=pts/0 res=success'
----
type=LOGIN msg=audit(08/31/2015 20:30:21.466:20) : pid=2085 uid=root subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 old auid=unset new auid=root old ses=unset new ses=2
----
type=USER_AUTH msg=audit(09/21/2015 16:45:31.927:20) : user pid=2386 uid=root auid=unset ses=unset subj=system_u:system_r:local_login_t:s0-s0:c0.c1023 msg='op=PAM:authentication acct=root exe=/bin/login hostname=? addr=? terminal=tty1 res=success'
----
type=CRYPTO_KEY_USER msg=audit(09/22/2015 02:06:57.511:20) : user pid=2201 uid=root auid=root ses=1 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=server fp=97:8b:22:1c:92:9d:f9:b7:b5:96:ee:f2:c5:3b:d5:59 direction=? spid=2201 suid=root  exe=/usr/sbin/sshd hostname=? addr=192.168.1.6 terminal=pts/0 res=success'
----
type=CRYPTO_KEY_USER msg=audit(09/22/2015 22:55:13.412:20) : user pid=2196 uid=root auid=root ses=1 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=server fp=97:8b:22:1c:92:9d:f9:b7:b5:96:ee:f2:c5:3b:d5:59 direction=? spid=2196 suid=root  exe=/usr/sbin/sshd hostname=? addr=192.168.1.6 terminal=pts/0 res=success'
----
type=CRYPTO_KEY_USER msg=audit(09/23/2015 20:54:36.517:20) : user pid=2198 uid=root auid=root ses=1 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=server fp=97:8b:22:1c:92:9d:f9:b7:b5:96:ee:f2:c5:3b:d5:59 direction=? spid=2198 suid=root  exe=/usr/sbin/sshd hostname=? addr=192.168.1.6 terminal=pts/0 res=success'

Nie będę tu dokonywał analizy wyników zapytania, ponieważ nie to było celem tego tekstu. Opierając się na nim możesz natomiast dość sprawnie sam sprawdzić co działo się w systemie...

Brak komentarzy:

Prześlij komentarz