Jak pracować z dziennikami Zimbra OSE

Rejestrowanie wszystkich zachodzących zdarzeń jest jedną z najważniejszych funkcji każdego systemu korporacyjnego. Logi pozwalają rozwiązywać pojawiające się problemy, audytować działanie systemów informatycznych, a także badać incydenty związane z bezpieczeństwem informacji. Zimbra OSE prowadzi również szczegółowe dzienniki swojego działania. Obejmują one wszystkie dane, od wydajności serwera po wysyłanie i odbieranie wiadomości e-mail przez użytkowników. Jednakże odczytanie logów generowanych przez Zimbra OSE jest zadaniem raczej nietrywialnym. W tym artykule na konkretnym przykładzie podpowiemy jak czytać logi Zimbra OSE, a także jak je scentralizować.

Jak pracować z dziennikami Zimbra OSE
Zimbra OSE przechowuje wszystkie lokalne dzienniki w folderze /opt/zimbra/log, a dzienniki można również znaleźć w pliku /var/log/zimbra.log. Najważniejszym z nich jest mailbox.log. Rejestruje wszystkie działania, które mają miejsce na serwerze pocztowym. Należą do nich przesyłanie wiadomości e-mail, danych uwierzytelniających użytkownika, nieudanych prób logowania i inne. Wpisy w mailbox.log to ciąg tekstowy zawierający czas wystąpienia zdarzenia, poziom zdarzenia, numer wątku, w którym zdarzenie miało miejsce, nazwę użytkownika i adres IP oraz tekstowy opis zdarzenia .

Jak pracować z dziennikami Zimbra OSE

Poziom logowania wskazuje stopień wpływu zdarzenia na pracę serwera. Domyślnie dostępne są 4 poziomy zdarzeń: INFO, WARN, ERROR i FATAL. Przyjrzyjmy się wszystkim poziomom w kolejności rosnącej ważności.

  • INFO - Wydarzenia na tym poziomie mają zazwyczaj na celu informowanie o postępie Zimbra OSE. Wiadomości na tym poziomie zawierają raporty dotyczące utworzenia lub usunięcia skrzynki pocztowej i tak dalej.
  • OSTRZEŻAJ - zdarzenia tego poziomu informują o sytuacjach potencjalnie niebezpiecznych, ale nie mają wpływu na działanie serwera. Przykładowo poziom WARN oznacza komunikat o nieudanej próbie logowania użytkownika.
  • BŁĄD - ten poziom zdarzenia w logu informuje o wystąpieniu błędu, który ma charakter lokalny i nie zakłóca pracy serwera. Na tym poziomie można oznaczyć błąd polegający na uszkodzeniu danych indeksu pojedynczego użytkownika.
  • FATAL - poziom ten wskazuje błędy, przez które serwer nie może normalnie działać. Przykładowo poziom FATAL będzie dotyczył rekordu wskazującego na brak możliwości połączenia z SZBD.

Plik dziennika serwera poczty jest aktualizowany codziennie. Najnowsza wersja pliku ma zawsze nazwę Mailbox.log, natomiast logi z określonej daty mają w nazwie datę i znajdują się w archiwum. Na przykład mailbox.log.2020-09-29.tar.gz. Dzięki temu znacznie łatwiej jest tworzyć kopie zapasowe dzienników aktywności i przeszukiwać dzienniki.

Dla wygody administratora systemu folder /opt/zimbra/log/ zawiera inne logi. Zawierają one jedynie wpisy odnoszące się do konkretnych elementów Zimbra OSE. Na przykład plik audytu.log zawiera tylko zapisy dotyczące uwierzytelnienia użytkownika, plik clamd.log zawiera dane dotyczące działania programu antywirusowego i tak dalej. Nawiasem mówiąc, doskonałą metodą ochrony serwera Zimbra OSE przed intruzami jest ochrona serwera za pomocą Fail2Ban, który działa po prostu w oparciu o plik audytu.log. Dobrą praktyką jest również dodanie zadania cron w celu wykonania polecenia grep -ir „nieprawidłowe hasło” /opt/zimbra/log/audit.logaby otrzymywać codzienne informacje o błędach logowania.

Jak pracować z dziennikami Zimbra OSE
Przykład tego, jak audyt.log pokazuje dwukrotnie błędnie wprowadzone hasło i udaną próbę logowania.

Logi w Zimbra OSE mogą być niezwykle przydatne w identyfikowaniu przyczyn różnych krytycznych awarii. W momencie wystąpienia błędu krytycznego administrator zazwyczaj nie ma czasu na zapoznanie się z logami. Wymagane jest jak najszybsze przywrócenie serwera. Jednak później, gdy serwer wykona kopię zapasową i wygeneruje wiele dzienników, znalezienie wymaganego wpisu w dużym pliku może być trudne. Aby szybko znaleźć zapis błędu, wystarczy znać godzinę, o której serwer został zrestartowany i znaleźć w logach wpis z tego czasu. Poprzedni wpis będzie zapisem błędu, który wystąpił. Komunikat o błędzie można także znaleźć, wyszukując słowo kluczowe FATAL.

Dzienniki Zimbra OSE umożliwiają także identyfikację błędów niekrytycznych. Na przykład, aby znaleźć wyjątki obsługi, możesz wyszukać wyjątek obsługi. Często błędom generowanym przez procedury obsługi towarzyszy ślad stosu wyjaśniający, co spowodowało wyjątek. W przypadku błędów w dostarczaniu poczty wyszukiwanie należy rozpocząć od słowa kluczowego LmtpServer, natomiast do wyszukiwania błędów związanych z protokołami POP lub IMAP można posłużyć się słowami kluczowymi ImapServer i Pop3Server.

Dzienniki mogą być również pomocne podczas badania incydentów związanych z bezpieczeństwem informacji. Spójrzmy na konkretny przykład. 20 września jeden z pracowników wysłał do klienta zainfekowany list. W efekcie dane znajdujące się na komputerze Klienta zostały zaszyfrowane. Pracownik jednak przysięga, że ​​nic nie wysłał. W ramach dochodzenia w sprawie incydentu służba bezpieczeństwa przedsiębiorstwa żąda od administratora systemu dzienników serwera pocztowego z 20 września powiązanych z użytkownikiem objętym dochodzeniem. Dzięki znacznikowi czasu administrator systemu odnajduje niezbędny plik dziennika, wyodrębnia niezbędne informacje i przekazuje je specjalistom ds. bezpieczeństwa. Ci z kolei przeglądają go i stwierdzają, że adres IP, z którego wysłano ten list, odpowiada adresowi IP komputera użytkownika. Nagranie z monitoringu potwierdziło, że w momencie wysłania pisma pracownik przebywał w miejscu pracy. Dane te wystarczyły, aby oskarżyć go o naruszenie zasad bezpieczeństwa informacji i zwolnić. 

Jak pracować z dziennikami Zimbra OSE
Przykład wyodrębnienia zapisów o jednym z kont z logu Mailbox.log do osobnego pliku

Wszystko staje się znacznie bardziej skomplikowane, jeśli chodzi o infrastrukturę wieloserwerową. Ponieważ logi gromadzone są lokalnie, praca z nimi w infrastrukturze wieloserwerowej jest bardzo niewygodna i dlatego istnieje potrzeba scentralizowania gromadzenia logów. Można to zrobić, konfigurując hosta do zbierania dzienników. Nie ma szczególnej potrzeby dodawania dedykowanego hosta do infrastruktury. Dowolny serwer pocztowy może pełnić rolę węzła zbierającego logi. W naszym przypadku będzie to węzeł Mailstore01.

Na tym serwerze musimy wprowadzić poniższe polecenia:

sudo su – zimbra 
zmcontrol stop
exit
sudo /opt/zimbra/libexec/zmfixperms -e -v

Edytuj plik /etc/sysconfig/rsyslog i ustaw SYSLOGD_OPTIONS=”-r -c 2″

Edytuj plik /etc/rsyslog.conf i odkomentuj następujące wiersze:
$ModLoad imudp
$UDPServerRun 514

Wpisz następujące polecenia:

sudo /etc/init.d/rsyslog stop
sudo /etc/init.d/rsyslog start
sudo su – zimbra
zmcontrol start
exit
sudo /opt/zimbra/libexec/zmloggerinit
sudo /opt/zimbra/bin/zmsshkeygen
sudo /opt/zimbra/bin/zmupdateauthkeys

Możesz sprawdzić, czy wszystko działa, używając polecenia zmprov gacf | grep zimbraLogNazwa_hosta. Po wykonaniu polecenia powinna wyświetlić się nazwa hosta zbierającego logi. Aby to zmienić, musisz wprowadzić polecenie zmprov mcf zimbraLogHostname mailstore01.company.ru.

Na wszystkich pozostałych serwerach infrastruktury (LDAP, MTA i inne magazyny poczty) uruchom komendę zmprov gacf |grep zimbraLogHostname, aby zobaczyć nazwę hosta, do którego wysyłane są dzienniki. Aby to zmienić, możesz także wprowadzić polecenie zmprov mcf zimbraLogHostname mailstore01.company.ru

Musisz także wprowadzić następujące polecenia na każdym serwerze:

sudo su - zimbra
/opt/zimbra/bin/zmsshkeygen
/opt/zimbra/bin/zmupdateauthkeys
exit
sudo /opt/zimbra/libexec/zmsyslogsetup
sudo service rsyslog restart
sudo su - zimbra
zmcontrol restart

Następnie wszystkie logi zostaną zapisane na wskazanym przez Ciebie serwerze, gdzie będzie można je wygodnie przeglądać. Również w konsoli administratora Zimbra OSE, na ekranie z informacją o stanie serwerów, uruchomiona usługa Logger zostanie wyświetlona tylko dla serwera mailstore01.

Jak pracować z dziennikami Zimbra OSE

Kolejnym problemem dla administratora może być śledzenie konkretnego e-maila. Ponieważ wiadomości e-mail w Zimbra OSE przechodzą przez kilka różnych zdarzeń jednocześnie: skanowanie przez program antywirusowy, antyspam itd., przed przyjęciem lub wysłaniem, dla administratora, jeśli wiadomość e-mail nie dotrze, śledzenie, na jakim etapie może być dość problematyczne zostało utracone.

Aby rozwiązać ten problem, możesz użyć specjalnego skryptu, który został opracowany przez specjalistę ds. bezpieczeństwa informacji Viktora Dukhovnego i zalecany do użytku przez programistów Postfix. Skrypt ten łączy wpisy z logów dla konkretnego procesu i dzięki temu pozwala na szybkie wyświetlenie wszystkich wpisów związanych z wysłaniem danego listu na podstawie jego identyfikatora. Jego działanie zostało przetestowane na wszystkich wersjach Zimbra OSE, począwszy od 8.7. Oto tekst scenariusza.

#! /usr/bin/perl

use strict;
use warnings;

# Postfix delivery agents
my @agents = qw(discard error lmtp local pipe smtp virtual);

my $instre = qr{(?x)
	A			# Absolute line start
	(?:S+ s+){3} 		# Timestamp, adjust for other time formats
	S+ s+ 		# Hostname
	(postfix(?:-[^/s]+)?)	# Capture instance name stopping before first '/'
	(?:/S+)*		# Optional non-captured '/'-delimited qualifiers
	/			# Final '/' before the daemon program name
	};

my $cmdpidre = qr{(?x)
	G			# Continue from previous match
	(S+)[(d+)]:s+	# command[pid]:
};

my %smtpd;
my %smtp;
my %transaction;
my $i = 0;
my %seqno;

my %isagent = map { ($_, 1) } @agents;

while (<>) {
	next unless m{$instre}ogc; my $inst = $1;
	next unless m{$cmdpidre}ogc; my $command = $1; my $pid = $2;

	if ($command eq "smtpd") {
		if (m{Gconnect from }gc) {
			# Start new log
			$smtpd{$pid}->{"log"} = $_; next;
		}

		$smtpd{$pid}->{"log"} .= $_;

		if (m{G(w+): client=}gc) {
			# Fresh transaction 
			my $qid = "$inst/$1";
			$smtpd{$pid}->{"qid"} = $qid;
			$transaction{$qid} = $smtpd{$pid}->{"log"};
			$seqno{$qid} = ++$i;
			next;
		}

		my $qid = $smtpd{$pid}->{"qid"};
		$transaction{$qid} .= $_
			if (defined($qid) && exists $transaction{$qid});
		delete $smtpd{$pid} if (m{Gdisconnect from}gc);
		next;
	}

	if ($command eq "pickup") {
		if (m{G(w+): uid=}gc) {
			my $qid = "$inst/$1";
			$transaction{$qid} = $_;
			$seqno{$qid} = ++$i;
		}
		next;
	}

	# bounce(8) logs transaction start after cleanup(8) already logged
	# the message-id, so the cleanup log entry may be first
	#
	if ($command eq "cleanup") {
		next unless (m{G(w+): }gc);
		my $qid = "$inst/$1";
		$transaction{$qid} .= $_;
		$seqno{$qid} = ++$i if (! exists $seqno{$qid});
		next;
	}

	if ($command eq "qmgr") {
		next unless (m{G(w+): }gc);
		my $qid = "$inst/$1";
		if (defined($transaction{$qid})) {
			$transaction{$qid} .= $_;
			if (m{Gremoved$}gc) {
				print delete $transaction{$qid}, "n";
			}
		}
		next;
	}

	# Save pre-delivery messages for smtp(8) and lmtp(8)
	#
	if ($command eq "smtp" || $command eq "lmtp") {
		$smtp{$pid} .= $_;

		if (m{G(w+): to=}gc) {
			my $qid = "$inst/$1";
			if (defined($transaction{$qid})) {
				$transaction{$qid} .= $smtp{$pid};
			}
			delete $smtp{$pid};
		}
		next;
	}

	if ($command eq "bounce") {
		if (m{G(w+): .*? notification: (w+)$}gc) {
			my $qid = "$inst/$1";
			my $newid = "$inst/$2";
			if (defined($transaction{$qid})) {
				$transaction{$qid} .= $_;
			}
			$transaction{$newid} =
				$_ . $transaction{$newid};
			$seqno{$newid} = ++$i if (! exists $seqno{$newid});
		}
		next;
	}

	if ($isagent{$command}) {
		if (m{G(w+): to=}gc) {
			my $qid = "$inst/$1";
			if (defined($transaction{$qid})) {
				$transaction{$qid} .= $_;
			}
		}
		next;
	}
}

# Dump logs of incomplete transactions.
foreach my $qid (sort {$seqno{$a} <=> $seqno{$b}} keys %transaction) {
    print $transaction{$qid}, "n";
}

Skrypt napisany jest w języku Perl i aby go uruchomić należy zapisać go do pliku sortuj.pl, uczyń go wykonywalnym, a następnie uruchom plik, podając plik dziennika i używając pgrep do wyodrębnienia informacji identyfikacyjnych szukanej litery collate.pl /var/log/zimbra.log | pgrep'[email chroniony]>'. Wynikiem będzie sekwencyjne wyjście linii zawierających informację o ruchu listu na serwerze.

# collate.pl /var/log/zimbra.log | pgrep '<[email protected]>'
Oct 13 10:17:00 mail postfix/pickup[4089]: 4FF14284F45: uid=1034 from=********
Oct 13 10:17:00 mail postfix/cleanup[26776]: 4FF14284F45: message-id=*******
Oct 13 10:17:00 mail postfix/qmgr[9946]: 4FF14284F45: from=********, size=1387, nrcpt=1 (queue active)
Oct 13 10:17:00 mail postfix/smtp[7516]: Anonymous TLS connection established to mail.*******[168.*.*.4]:25: TLSv1 with cipher ADH-AES256-SHA (256/256 bits)
Oct 13 10:17:00 mail postfix/smtp[7516]: 4FF14284F45: to=*********, relay=mail.*******[168.*.*.4]:25, delay=0.25, delays=0.02/0.02/0.16/0.06, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 878833424CF)
Oct 13 10:17:00 mail postfix/qmgr[9946]: 4FF14284F45: removed
Oct 13 10:17:07 mail postfix/smtpd[21777]: connect from zimbra.******[168.*.*.4]
Oct 13 10:17:07 mail postfix/smtpd[21777]: Anonymous TLS connection established from zimbra.******[168.*.*.4]: TLSv1 with cipher ADH-AES256-SHA (256/256 bits)
Oct 13 10:17:08 mail postfix/smtpd[21777]: 0CB69282F4E: client=zimbra.******[168.*.*.4]
Oct 13 10:17:08 mail postfix/cleanup[26776]: 0CB69282F4E: message-id=zimbra.******
Oct 13 10:17:08 mail postfix/qmgr[9946]: 0CB69282F4E: from=zimbra.******, size=3606, nrcpt=1 (queue active)
Oct 13 10:17:08 mail postfix/virtual[5291]: 0CB69282F4E: to=zimbra.******, orig_to=zimbra.******, relay=virtual, delay=0.03, delays=0.02/0/0/0.01, dsn=2.0.0, status=sent (delivered to maildir)
Oct 13 10:17:08 mail postfix/qmgr[9946]: 0CB69282F4E: removed

W przypadku wszystkich pytań związanych z Zextras Suite, możesz skontaktować się z przedstawicielem Zextras Ekaterina Triandafilidi przez e-mail [email chroniony]

Źródło: www.habr.com