Logging of all occurring events is one of the most important functions of any corporate system. Logs allow you to solve emerging problems, audit the operation of information systems, and also investigate information security incidents. Zimbra OSE also keeps detailed logs of its work. They include all data from server performance to sending and receiving emails by users. However, reading the logs generated by Zimbra OSE is a rather non-trivial task. In this article, using a specific example, we will tell you how to read Zimbra OSE logs, as well as how to make them centralized.
Zimbra OSE stores all local logs in the /opt/zimbra/log folder, and logs can also be found in the /var/log/zimbra.log file. The most important of these is mailbox.log. It records all actions that occur on the mail server. Among them are the transmission of letters, user authentication data, unsuccessful login attempts, and others. Entries in mailbox.log are a text string that contains the time at which the event occurred, the level of the event, the number of the stream within which the event occurred, the username and its ip-address, and a text description of the event.
The log level indicates the degree of influence of the event on the operation of the server. By default, 4 event levels are used: INFO, WARN, ERROR and FATAL. Let's analyze all the levels in ascending order of their severity.
- INFO - events at this level are usually designed to inform about the progress of the Zimbra OSE. Among the messages of this level are reports on the creation or deletion of a mailbox, and so on.
- WARN - events of this level inform about situations that are potentially dangerous, but do not affect the operation of the server. The WARN level, for example, marks a message about an unsuccessful user login attempt.
- ERROR - this event level in the log informs about the occurrence of an error that is local in nature and does not interfere with the operation of the server. This level can mark an error in which the index data of an individual user is corrupted.
- FATAL - Errors that prevent the server from continuing to function normally are marked with this level. For example, the FATAL level will be in the record about the inability to connect to the DBMS.
The mail server log file is updated every day. The latest version of the file is always named Mailbox.log, while the logs for a certain date have a date in the title and are contained in the archive. For example mailbox.log.2020-09-29.tar.gz. This greatly simplifies the backup of activity logs and search through the logs.
For the convenience of the system administrator, the /opt/zimbra/log/ folder contains other logs. They include only those entries that relate to specific Zimbra OSE elements. For example, audit.log contains only entries about user authentication, clamd.log contains data about antivirus operation, and so on. By the way, an excellent method of protecting the Zimbra OSE server from intruders is , which just works based on audit.log. It is also good practice to add a cron task to execute the command grep -ir "invalid password" /opt/zimbra/log/audit.logto receive daily information about failed login attempts.
An example of how the audit.log shows a double invalid password and a successful login attempt
The logs in Zimbra OSE can be extremely helpful in figuring out the causes of various critical failures. At the moment when a critical error occurs, the administrator usually has no time to read the logs. The server needs to be restored as soon as possible. However, later, when the server is back up and generating a lot of logs, it can be difficult to find the right entry in a large file. In order to quickly find an error entry, it is enough to know the time at which the server was restarted and find an entry in the logs dated to this time. The previous record will be the error record. You can also find the error message by searching for the FATAL keyword.
Also, the Zimbra OSE logs allow you to detect non-critical failures. For example, to find handler exceptions, you can search for the phrase handler exception. Often, the errors generated by handlers are accompanied by a stack trace that explains what caused the exception to occur. In case of mail delivery errors, you should start your search with the LmtpServer keyword, and to search for errors related to the POP or IMAP protocols, you can use the ImapServer and Pop3Server keywords.
Logs can also help in the investigation of information security incidents. Let's consider a specific example. On September 20, one of the employees sent a virus-infected letter to the client. As a result, the data on the client's computer was encrypted. However, the employee swears that he did not send anything. As part of the investigation of the incident, the enterprise security service requests from the system administrator the mail server logs for September 20 associated with the user under investigation. Thanks to the timestamp, the system administrator finds the right log file, extracts the necessary information and passes it to the security guards. Those, in turn, view it and find that the IP address from which this letter was sent matches the IP address of the user's computer. CCTV footage confirmed that the employee was at his workplace when the letter was sent. This data was enough to accuse him of violating information security rules and fire him.
An example of extracting records about one of the accounts from the Mailbox.log log into a separate file
Things get much more complicated when it comes to multi-server infrastructure. Since the logs are collected locally, it is very inconvenient to work with them in a multi-server infrastructure, and therefore it becomes necessary to centralize the collection of logs. You can do this by setting up a host for collecting logs. There is no special need to add a dedicated host to the infrastructure. Any mail server can act as a host for collecting logs. In our case, this will be the Mailstore01 node.
On this server, we need to enter the commands below:
sudo su β zimbra
zmcontrol stop
exit
sudo /opt/zimbra/libexec/zmfixperms -e -vEdit the /etc/sysconfig/rsyslog file, and set the SYSLOGD_OPTIONS="-r -c 2" option
Edit /etc/rsyslog.conf and uncomment the following lines:
$ModLoad imudp
$UDPServerRun 514
Enter the following commands:
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/zmupdateauthkeysYou can check that everything is working using the zmprov gacf | grep zimbraLogHostname. After executing the command, the name of the host that collects the logs should be displayed. In order to change it, you must enter the command zmprov mcf zimbraLogHostname mailstore01.company.ru.
On all other infrastructure servers (LDAP, MTA, and other mail storages), run the zmprov gacf |grep zimbraLogHostname command to see the name of the host where the logs go. To change it, you can also enter the command zmprov mcf zimbraLogHostname mailstore01.company.ru
Also, on each server, you must enter the following commands:
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 restartAfter that, all logs will be recorded on the server you specified, where they can be conveniently viewed. Also, in the Zimbra OSE admin console, on the screen with information about the status of the servers, the running Logger service will only be displayed on the mailstore01 server.
Keeping track of a particular email message can be another headache for an administrator. Since emails in Zimbra OSE go through several different events at once: checking by antivirus, antispam, and so on, before being accepted or sent, for the administrator, if the email does not reach, it can be quite problematic to trace at what stage it was lost .
In order to solve this problem, you can use a special script, which was developed by information security specialist Viktor Dukhovny and is recommended for use by Postfix developers. This script concatenates records from the logs for a specific process and, due to this, allows you to quickly display all records related to the sending of a particular letter based on its identifier. Its work has been tested on all versions of Zimbra OSE, starting from 8.7. Here is the text of the script.
#! /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";
}The script is written in Perl and to run it you need to save it to a file collate.pl, make it executable, then run the file specifying the log file and use pgrep to extract the identification information of the email you are looking for collate.pl /var/log/zimbra.log | pgrep'[email protected]>'. The result will be a sequential output of lines that contain information about the movement of the letter on the server.
# 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: removedFor all questions related to Zextras Suite, you can contact the Representative of Zextras Ekaterina Triandafilidi by e-mail [email protected]
Source: habr.com