Настройка уровня журналирования в Zimbra OSE

Additional content

Looking for a Video?

Visit our YouTube channel to get the latest webinars, technology news, product overviews, and so much more.
Go to the YouTube channel »

Wiki/KB reviewed by SME1 SME2 Copyeditor Last edit by Jorge de la Cruz

Mailbox.log: the king of zimbra log files – zimbra : blog

As many of our Administrators know, Zimbra Collaboration Suite logs just about everything. One of the most integral is the mailbox.log located in /opt/zimbra/log .

In this Administrator’s PowerTip, we’ll cover some common entries in the mailbox.log file, and what they mean.
*Note- This is an administrator PowerTip intended for System Administrators of Zimbra Collaboration Suite.

Настройка уровня журналирования в Zimbra OSE
Administrator’s PowerTip #1: May 7, 2007
Zimbra Forums – Zimbra wiki –

Zimbra Blog


Introduction

Настройка уровня журналирования в Zimbra OSEZimbra Collaboration Suite leverages the power of many different applications to deliver the best, and most advanced user experience available. Most of these have been rigorously tested to insure that they can survive in a high demand production environment.

A good example of this high demand production environment, is the partnership with Comcast that Zimbra reached.

However, sometimes things can go wrong. The symptoms can very, and the logs should be the very first resource to finding out what’s happening.

In Fig. 1, we see that tomcat has started, but the user cannot login.

/opt/zimbra/log/mailbox.log – General Notices

In ZCS version 4.5, we changed the /opt/zimbra/log/zimbra.log to /opt/zimbra/log/mailbox.log to avoid confusion with another Zimbra log.

This is a particularly powerful log that contains much information to help out a system administrator.

On a normally functioning system, this log file will log items such as authentication sessions, POP3/IMAP/SOAP access, and blob file stores. More importantly, it logs most errors such as authentication, ssh, tomcat, and other failures.

In the above snippet, we see an informational message about a delivery. In order, we have:
Date; Time; Type of Message; LMTP=Local Mail Transport Protocol; Thread #; User account that triggered the message.
The above message is more of an informational message, than an error message. There is also the WARN notice which is for warnings.

/opt/zimbra/log/mailbox.log – Exceptions & Stack Traces

In this example, we see that there has been an exception. An exception is an event, which occurs during the execution of a program, that disrupts the normal flow of the program’s instructions.
To most, this is Greek, but it’s actually quite informational!

We see that someone has logged in, and an error was detected. in order, we have:
Date; Time; Type of Message; Protocol-Port-Thread; User Agent; Error

In some cases, Zimbra will log a tomcat stack trace for more information. This becomes quite handy to post in our forums. In this case, the stack trace tells us that there is not a folder ID 890.
With a stack trace, always look for a “Caused By” line. This will tell you the root of the error.

In the above example, there won’t be a “Caused By” error because the error is caused by a user trying to access a non-existent folder.

/opt/zimbra/log/mailbox.log – Security

Security is a must. System administrators need to know if an unauthorized person/bot is trying to get into their system.
Mailbox.log will log any successful or unsuccessful login attempts via IMAP/POP3/SOAP

In the above example, someone ([email protected] ) has attempted to login to the server, but the authentication has failed. Important information such as the IP address, and the affected account are included.

For diagnostic purposes, a stacktrace is included. If you see a lot of these entires, then it is likely that you are victim to a brute force attack, or just a user who doesn’t know their password/Caps light is on.

For a more detailed security log, take a look at /opt/zimbra/log/audit.log

/opt/zimbra/log/mailbox.log – Tomcat failure

The above examples are common informational messages. Let’s look at some errors. An common error is to enable the IMAP Proxy service without configuring it. Because that service runs most commonly runs on port 80, this can cause a conflict with tomcat which also most commonly runs on port 80.

At first, the IMAP Proxy won’t start because it is attempting to bind to a port that is already in use. However, if the server reboots, IMAP Proxy will start before Tomcat. This means that when Tomcat tries to start, it won’t be able to bind to port 80, thus, no one can access Zimbra. In the above example, we see all of the Zimbra services running, except Tomcat, which handles the Zimbra Web Client.

There are also many other things that can bind to port 80, like Apache’s httpd service (only typical if you don’t use ssl/port 443).

Unfortunately, this won’t be logged into the mailbox.log, but will be logged in catalina.out.

/opt/zimbra/log/mailbox.log – Finding your error

As you’ve noticed, just about everything is logged into this log file. Sifting through the log can be difficult.

It might be good to clear the log by running:
cat /dev/null
> /opt/zimbra/log/mailbox.log

Then rerunning the operation that is causing the error.

The grep command along with a pipe, can be useful:
cat /opt/zimbra/log/mailbox.log | grep exception

Conclusion

There is a lot more to this log, that isn’t documented here. We’ll be posting more on that later.

The mailbox.log won’t log service status, so if LDAP fails to start, it won’t be logged here. Each service has it’s own log file (which we’ll cover later).
Remember that the mailbox.log is a “runtime” log, so it will log mostly runtime events.

The forums can be your best friend when it comes to troubleshooting. Just search for your error using Zimbra’s advanced searching feature, and you’ll probably find an answer. If not, then please post your issue.

Don’t forget to include the mailbox.log in your post.

Resolution

‘zmmsgtrace’ can be used for this. This parses the logs by showing only the sender and receiver, and the time the email was sent.

Как работать с логами zimbra ose | prohoster

Логирование всех происходящих событий — одна из наиболее важных функций любой корпоративной системы. Логи позволяют решать возникающие проблемы, проводить аудит работы информационных систем, а также расследовать инциденты информационной безопасности. 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 от злоумышленников является , которая как раз работает на основе 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 ‘<[email protected]>’. Результатом станет последовательный вывод строк, в которых содержится информация о движении письма на сервере.

# 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

По всем вопросам, связанными c Zextras Suite вы можете обратиться к Представителю компании «Zextras» Екатерине Триандафилиди по электронной почте [email protected]

Источник: habr.com

Похожее:  Всё Супер | Услуги частным клиентам | Официальный сайт МТС - Балашиха

Добавить комментарий

Ваш адрес email не будет опубликован. Обязательные поля помечены *

➤