Our last article talked about Exim utilities. The utilities we looked at are used to inspect the mail queue or individual emails. This article looks at Exim’s log files and the
exigrep is mainly used to get information about email deliveries. We will therefore also look at various types of errors you might see in the logs.
There are three Exim log files:
By default the logs are rotated every week. The current (not-yet-rotated) log is a plain text file. Older logs may be zipped, depending on the log rotation settings. So, you may need to unzip old logs before you can work with them.
Most entries in /var/log/maillog are made up of multiple lines. The first line typically contains information about the email itself, such as the date, sender and recipient. Subsequent lines show information about how the email was delivered. When you inspect the log you therefore want complete entries rather than individual lines. The
exigrep utility does just that. You can search for an Exim ID, email address or whatever else, and it will return all the relevant information.
exigrep also separates entries with whitespace, which makes it much easier to read the log. And, it uses a pager, so that you get to see one page at the time. The pager works exactly like
Each entry contains a lot of information, and the entries are terse. Let’s first look at an example of an email that was delivered correctly. We have slightly simplified the log entry for readability:
# exigrep paypal.co.uk /var/log/exim_mainlog 2020-02-09 10:31:43 1j0jsN-0002hA-Li <= firstname.lastname@example.org T="Notification of Payment Received" for email@example.com 2020-02-09 10:31:43 1j0jsN-0002hA-Li => sales <firstname.lastname@example.org> R=virtual_user T=dovecot_virtual_delivery 2020-02-09 10:31:43 1j0jsN-0002hA-Li Completed
Let’s break that down…
The log file lists both incoming and outgoing emails. Incoming emails have the status indicator
<= email@example.com means that Exim received an email from firstname.lastname@example.org. Outgoing emails use the indicator
In addition, there are two other indicators you might come across:
==the delivery has been deferred because of a temporary problem
**the delivery has failed
Let’s return to our example email. The second line shows the email was delivered to email@example.com. The router (
R=) used was virtual_user and the transport (
T=) was dovecot_virtual_delivery. What this means is that the email was delivered to a user on the server. It is worth noting that emails for local users are delivered by Dovecot rather than Exim.
Remote deliveries are always managed by Exim. In that case Exim looks up where the email should be delivered to. Here is an example:
2020-02-09 03:43:36 1j0dVQ-0002eQ-CZ <= firstname.lastname@example.org U=example T="Please moderate: \"Hello World!"" for email@example.com 2020-02-09 03:43:36 1j0dVQ-0002eQ-CZ Sender identification U=example D=example.net Sfirstname.lastname@example.org 2020-02-09 03:43:36 1j0dVQ-0002eQ-CZ SMTP connection outbound 1581219816 1j0dVQ-0002eQ-CZ example.net email@example.com 2020-02-09 03:43:38 1j0dVQ-0002eQ-CZ => firstname.lastname@example.org R=lookuphost T=remote_smtp H=cluster3.eu.messagelabs.com [22.214.171.124] Message accepted for delivery" 2020-02-09 03:43:38 1j0dVQ-0002eQ-CZ Completed
This email was sent from the example.net website (it is a WordPress comment moderation email). The email has one recipient: email@example.com. Because catalyst2.com doesn’t live on the server Exim looked up where catalyst2.com does live (
R=lookuphost). It next sent the email to the remote server. The log entry also shows that the remote server accepted the email for delivery.
If these two examples made sense then you can already debug many common issues. Let’s run through some examples.
cPanel servers let users select whether incoming emails should be routed locally or remotely. This can cause delivery issues. For instance, let’s imagine that the domain example.net uses G Suite for email:
# dig example.net MX +short | sort -h 1 aspmx.l.google.com. 5 alt1.aspmx.l.google.com. 5 alt2.aspmx.l.google.com. 10 alt3.aspmx.l.google.com. 10 alt4.aspmx.l.google.com.
Because mail for example.net is handled by an external server the mail exchanger should be set to “remote”. Email deliveries will fail if it is set to “local” instead. Exim would pass the email to Dovecot, which in turn wouldn’t be able to deliver the email locally.
2020-02-11 17:09:46 1j1Z2g-00Faoy-Uh <= firstname.lastname@example.org U=example P=local T="[Examples Galore] Please moderate: \"Hello world!\"" for email@example.com 2020-02-11 17:09:47 1j1Z2g-00Faoy-Uh ** firstname.lastname@example.org R=virtual_aliases: No such person at this address. 2020-02-11 17:09:47 1j1Z2g-00Faoy-Uh Completed
The above email bounced. Emails may also be frozen in the mail queue. In that case Exim tries to deliver the email at a later time:
# exigrep 1j1Z0U-00Fab5-62 /var/log/exim_mainlog 2020-02-11 17:07:30 1j1Z0U-00Fab5-62 <= <> H=st2.mx.email-filter.net [126.96.36.199] T="Spam Quarantine Report" for email@example.com 2020-02-11 17:07:30 1j1Z0U-00Fab5-62 ** firstname.lastname@example.org R=virtual_aliases: No Such User Here" 2020-02-11 17:07:30 1j1Z0U-00Fab5-62 Frozen (delivery error message) 2020-02-11 17:24:05 1j1Z0U-00Fab5-62 Message is frozen
As said, Exim tries to redeliver emails that are stuck in the queue. You can check Exim’s “retry configuration” for a domain using the command
# exim -brt example.net Retry rule: * * F,2h,15m; G,16h,1h,1.5; F,4d,8h;
The retry configuration is rather complicated:
F,2h,15mmeans that Exim tries to deliver the email every 15 minutes for two hours.
G,16h,1h,1.5means that for the next 16 hours Exim tries to deliver the email at increasing intervals. It first tries to deliver the email after one hour. After that, it tries again after 1 hour * 1.5, and so forth.
F,4d,8his another fixed retry schedule. Exim tries to deliver the email every eight hours for four days.
Emails that haven’t been delivered by the end of the period are purged.
In the previous example we looked at an email that couldn’t be delivered because the mailbox didn’t exist. There are many other reasons why an email can’t be delivered. Here is an incoming email that can’t be delivered because the mailbox is full:
2020-02-09 11:00:56 1j0kKd-002txk-OI <= email@example.com T="Notification of Payment Received" for firstname.lastname@example.org 2020-02-09 11:00:56 1j0kKd-002txk-OI == email@example.com R=virtual_user T=dovecot_virtual_delivery defer (-44): LMTP error after RCPT TO:<firstname.lastname@example.org>: 452 4.2.2 <email@example.com> Mailbox is full / Blocks limit exceeded / Inode limit exceeded 2020-02-09 11:46:41 1j0kKd-002txk-OI == firstname.lastname@example.org R=virtual_user T=dovecot_virtual_delivery defer (-52): Retry time not yet reached 2020-02-09 12:43:34 1j0kKd-002txk-OI == email@example.com R=virtual_user T=dovecot_virtual_delivery defer (-52): Retry time not yet reached ...
Remote servers can of course also reject emails coming from your server. Such emails usually have a bounce message that explains why the email was rejected. Common issues are that the recipient’s mailbox doesn’t exist or is full; that the email has been identified as spam or that sending domain’s SPF record doesn’t allow the IP address to send emails for the domain. Here are some examples:
Our system has detected an unusual rate of unsolicited mail originating from your IP address. To protect our users from spam, mail sent from your IP address has been temporarily rate limited. Please visit https://support.google.com/mail/?p=UnsolicitedRateLimitError to review our Bulk Email Senders Guidelines.
552-5.7.0 This message was blocked because its content presents a potential security issue. Please visit https://support.google.com/mail/?p=BlockedMessage to review our message content and attachment content guidelines.
450-4.2.1 The user you are trying to contact is receiving mail at a rate that prevents additional messages from being delivered. Please resend your message at a later time. If the user is able to receive mail at that time, your message will be delivered. For more information, please visit https://support.google.com/mail/?p=ReceivingRate.
554 Message rejected on 2020/02/10 21:45:26 GMT, policy (188.8.131.52) – Your message looks like SPAM or has been reported as SPAM.
552 5.2.2 Mailbox size limit exceeded.
550 Message was blocked by server (failed SPF).
As you can see, most bounce messages are very helpful. They clearly explain what the issue is.
cPanel users can create filter rules for emails. This is, for better or worse, often used to combat spam. Unfortunately, it is very easy to create a rule that accidentally matches a perfectly legitimate email.
Here is an example of an email that was removed because of an email filter:
2020-02-09 06:15:34 1j0fsU-002MCC-Uo <= firstname.lastname@example.org T="Currency Compare \"payday loans for bad credit\"" for email@example.com 2020-02-09 06:15:35 1j0fsU-002MCC-Uo => /dev/null <firstname.lastname@example.org> R=central_filter T=**bypassed** 2020-02-09 06:15:35 1j0fsU-002MCC-Uo Completed
The router central_filter indicates that the email matched a filter rule created by the cPanel user. As a result, the email was sent to /dev/null. This is a special file on Unix systems that simply discards anything sent to it. So, the email was purged.
In addition to user filters there are also server-wide filters. Such filters use the router system_filter instead.
You can double-check if the email was indeed purged because of a user filter. Filter rules for an individual mailbox are stored in /home/$user/etc/$domain/$mailbox/, while rules that apply to all mailboxes on an account are kept in /etc/vfilters/$domain. Here is an example of a filter rule in the latter file:
# grep -iA 3 "currency" /etc/vfilters/example.net #Spam - Currency Compare if $header_subject: contains "Currency Compare" then save "/dev/null" 660 endif