Як працювати з логами Zimbra OSE

Логування всіх подій, що відбуваються, — одна з найважливіших функцій будь-якої корпоративної системи. Логи дозволяють вирішувати проблеми, проводити аудит роботи інформаційних систем, а також розслідувати інциденти інформаційної безпеки. Zimbra OSE також проводить докладні логи своєї роботи. Вони потрапляють усі дані від продуктивності сервера до відправлення та отримання листів користувачами. Проте читання логів, що генеруються Zimbra OSE, є досить нетривіальним завданням. У цій статті на конкретному прикладі ми розповімо вам про те, як читати логи Zimbra OSE, а також як зробити їх централізованими.

Як працювати з логами Zimbra OSE
Всі локальні логи Zimbra OSE зберігає в папці /opt/zimbra/log, а також логи можна знайти у файлі /var/log/zimbra.log. Найважливішим із них є mailbox.log. У ньому фіксуються всі дії, які відбуваються на поштовому сервері. Серед них передача листів, дані про автентифікацію користувачів, невдалі спроби входу та інші. Записи в mailbox.log являють собою текстовий рядок, в якому міститься час, у який відбулася подія, рівень події, номер потоку, в рамках якого відбувалася подія, ім'я користувача та її ip-адресу, а також текстовий опис події.

Як працювати з логами Zimbra OSE

Рівень лога означає рівень впливу події на роботу сервера. За замовчуванням використовується 4 рівні подій: INFO, WARN, ERROR та FATAL. Розберемо всі рівні щодо зростання їх серйозності.

  • INFO — події на цьому рівні зазвичай мають інформувати про хід роботи Zimbra OSE. Серед повідомлень цього рівня звіти про створення або видалення поштової скриньки тощо
  • WARN — події цього рівня інформують про ситуації, які потенційно небезпечні, але на роботі сервера не позначаються. Наприклад, рівень WARN позначає повідомлення про невдалу спробу входу користувача.
  • ERROR - цей рівень події в лозі інформує про виникнення помилки, яка має локальний характер і не перешкоджає роботі сервера. Таким рівнем може бути помічена помилка, коли індексні дані окремого користувача виявилися пошкоджені.
  • FATAL – цим рівнем відзначаються помилки, через які сервер не може продовжувати нормально працювати. Наприклад, рівень FATAL буде у запису про неможливість підключитися до СУБД.

Файл із логами поштового сервера оновлюється щодня. Свіжа версія файлу завжди має ім'я Mailbox.log, у той час як логи за певне число мають дату в назві та містяться в архіві. Наприклад: mailbox.log.2020-09-29.tar.gz. Завдяки цьому значно спрощується резервування журналів дій та пошук по логах.

Для зручності системного адміністратора в папці /opt/zimbra/log/ містяться інші логи. Вони включені лише ті записи, які відносяться до конкретних елементів Zimbra OSE. Наприклад audit.log містять виключно записи про автентифікацію користувачів, в clamd.log дані про роботу антивірусу і так далі. До речі, чудовим методом захисту сервера Zimbra OSE від зловмисників є захист сервера за допомогою Fail2Ban, яка працює на основі audit.log. Також гарною практикою є додавання cron-завдання на виконання команди grep -ir „invalid password“ /opt/zimbra/log/audit.log, щоб щодня отримувати інформацію про випадки невдалих спроб входу.

Як працювати з логами Zimbra OSE
Приклад того, як у лозі audit.log відображаються двічі неправильно введений пароль та успішна спроба входу

Логи Zimbra OSE можуть бути дуже корисні при з'ясуванні причин різних критичних збоїв. У момент, коли відбувається критична помилка, адміністратор зазвичай не до читання логів. Потрібно якнайшвидше відновити роботу сервера. Однак потім, коли сервер знову працює і генерує безліч балок, знайти потрібний запис у великому файлі буває непросто. Для того, щоб швидко знайти запис про помилку, достатньо знати час, коли сервер був повторно запущений і знайти в логах запис датований цим часом. Попередній запис і буде записом про помилку, що відбулася. Також можна знайти повідомлення про помилку за допомогою пошуку за ключовим словом FATAL.

Також логи Zimbra OSE дозволяють виявляти і некритичні збої. Наприклад, щоб знайти винятки обробника, можна здійснити пошук за фразою handler exception. Нерідко помилки, які генерує обробники, супроводжуються трасуванням стека, в якому пояснюється, що стало причиною виникнення виключення. У разі помилок з доставкою пошти варто розпочати пошуки з ключового слова LmtpServer, а для пошуку помилок, пов'язаних з протоколами POP або IMAP, можна використовувати ключові слова ImapServer і Pop3Server.

Також логи можуть допомогти у розслідуванні інцидентів інформаційної безпеки. Розглянемо конкретний приклад. 20 вересня один із співробітників відправив клієнту заражений вірусом лист. В результаті дані на комп'ютері клієнта виявилися зашифрованими. Проте співробітник клянеться, що він нічого не відправляв. У рамках розслідування інциденту служба безпеки підприємства вимагає у системного адміністратора логи поштового сервера за 20 вересня, пов'язані з користувачем, щодо якого проводиться розслідування. Завдяки часовій позначці системний адміністратор знаходить потрібний файл із логами, витягує потрібну інформацію та передає її безпечним. Ті, у свою чергу, переглядають її і виявляють, що IP-адреса, з якої було відправлено цей лист, відповідає IP-адресі комп'ютера користувача. Записи камер відеоспостереження підтвердили, що працівник під час надсилання листа перебував на своєму робочому місці. Цих даних вистачило для того, щоб звинуватити його у порушенні правил інформаційної безпеки та звільнити. 

Як працювати з логами Zimbra OSE
Приклад вилучення записів про один з облікових записів із лога Mailbox.log в окремий файл

Все значно ускладнюється в той момент, коли йдеться про багатосерверну інфраструктуру. Оскільки логи збираються локально, працювати з ними в умовах мультисерверної інфраструктури дуже незручно і тому виникає потреба в централізації збору логів. Зробити це можна за рахунок налаштування хоста для збирання логів. Особливої ​​необхідності додавати до інфраструктури виділений хост немає. Як вузл для збору логів може виступати будь-який поштовий сервер. У нашому випадку це буде вузол Mailstore01.

На цьому сервері нам необхідно ввести наведені нижче команди:

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

Відредагуйте файл /etc/sysconfig/rsyslog та встановіть параметр SYSLOGD_OPTIONS=”-r -c 2″

Відредагуйте /etc/rsyslog.conf та розкоментуйте наступні рядки:
$ModLoad imudp
$UDPServerRun 514

Введіть такі команди:

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

Перевірити, чи все працює можна за допомогою команди zmprov gacf | grep zimbraLogHostname. Після виконання команди має відобразитись ім'я хоста, який здійснює збір логів. Щоб його змінити, необхідно ввести команду zmprov mcf zimbraLogHostname mailstore01.company.ru.

На інших серверах інфраструктури (LDAP, MTA та інших поштових сховищах) виконайте команду zmprov gacf |grep zimbraLogHostname, щоб побачити назву хоста, на які йдуть логи. Щоб його змінити, також можна ввести команду zmprov mcf zimbraLogHostname mailstore01.company.ru

Також на кожному сервері необхідно ввести такі команди:

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

Після цього всі логи будуть записуватися на вказаному сервері, де їх можна буде зручно переглядати. Також у консолі адміністратора Zimbra OSE на екрані з інформацією про стан серверів, запущена служба Logger відображатиметься лише на сервері mailstore01.

Як працювати з логами Zimbra OSE

Ще одним головним болем для адміністратора може стати відстеження певного повідомлення електронної пошти. Оскільки електронні листи в Zimbra OSE проходять відразу кілька різних подій: перевірка антивірусом, антиспамом і так далі, перед тим, як бути прийнятими або відправленими, для адміністратора, якщо електронний лист не доходить, може бути досить проблематично простежити, на якому етапі воно загубилося .

Для того, щоб вирішити цю проблему, можна скористатися спеціальним скриптом, розробленим фахівцем з інформаційної безпеки Віктором Духовним і рекомендованим для використання розробниками Postfix. Даний скрипт конкатенує записи з логів за певним процесом і завдяки цьому дозволяє швидко відобразити всі записи, пов'язані з відправкою того чи іншого листа на основі його ідентифікатора. Його роботу протестовано на всіх версіях Zimbra OSE, починаючи з 8.7. Наводимо текст скрипту.

#! /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";
}

Cкрипт написано на Perl і для його запуску необхідно зберегти його у файл collate.pl, зробити його виконуваним, а потім запустити файл із зазначенням файлу логів та за допомогою pgrep виділити ідентифікаційну інформацію шуканого листа collate.pl /var/log/zimbra.log | pgrep'[захищено електронною поштою]> '. Результатом стане послідовне виведення рядків, у яких міститься інформація про рух листа на сервері.

# 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

З усіх питань, пов'язаних з Zextras Suite ви можете звернутися до Представника компанії «Zextras» Катерини Тріандафіліді електронною поштою [захищено електронною поштою]

Джерело: habr.com