Sysadmin niceties

This page deals with a few miscellaneous issues that system administrators should consider.

Logrotate

On a busy mail server your /var/log/mail.log will grow quickly. That file not grow indefinitely thanks to the logrotate software that gets installed by default. Every day (controlled by cron - see the /etc/cron.daily/logrotate file) log files will get rotated. That means the old file "mail.log" gets renamed to "mail.log.1" and the Syslog daemon is restarted so it opens a new empty mail.log file. Upon the next rotation cycle the "mail.log.1" gets "mail.log.2" which will get compressed with GZip so it becomes a much smaller "mail.log.2.gz" file.

This is controlled by the /etc/logrotate.d/rsyslog file. By default is defines the rotation cycle a "weekly" and "rotate 4". So your mail.log is rotated once a week and after four rotation cycles the oldest file is deleted. Busy mail servers may need a daily rotation instead - so change the "weekly" to "daily". And if you have to provide log files for more than four rotation cycles then increase the number from "rotate 4" to e.g. "rotate 90" to make it 90 days.

Message queue and queue IDs

Understanding the Postfix mail queue is very useful. Postfix will put every accepted email into its queue before another Postfix process picks it up and tries to deliver it. You can see what emails are currently in your queue by running

mailq

in the shell. On a busy mail server you may have hundreds of email being stuck for various reasons. Maybe an ISP is throttling your mail server because you are sending unusual amounts of emails (easily happens when sending newsletters) or the destination mail server is currently unreachable. An example entry in the queue may look like this:

04D8CA8C442     2399 Tue May 31 09:49:11  MAILER-DAEMON
               (connect to mx.example.com[146.44.5.213]:25: Connection timed out)
                                         info@example.com

The "04D8CA8C442" is the queue ID. To see what happened with this email you can grep through your /var/log/mail.log file:

grep 04D8CA8C442 /var/log/mail.log

The output could be:

May 31 09:49:11 mx1 postfix/smtpd[4428]: 04D8CA8C442: client=web.localnet[10.10.41.3]
May 31 09:49:11 mx1 postfix/cleanup[4473]: 04D8CA8C442: message-id=<20110531094911.0A73631F59D@newsletter.example.net>
May 31 09:49:11 mx1 postfix/qmgr[25512]: 04D8CA8C442: from=<>, size=2399, nrcpt=1 (queue active)
May 31 09:49:41 mx1 postfix/smtp[4945]: 04D8CA8C442: to=<info@example.com>, relay=none, delay=30, delays=0.05/0.06/30/0, dsn=4.4.1, status=deferred (connect to mx.example.com[146.44.5.213]:25: Connection timed out)

The different Postfix processes that handled the email are shown after the "postfix/...". The "smtpd" received the email from the web.localnet server. Then the "cleanup" process put it into the mail queue. Next the "qmgr" moved the email into the active queue and the "smtp" tried to deliver it. The remote mail server mx.example.com could not be connected to so Postfix kept the email in the queue. The DSN (delivery status notification) code was 4.4.1. All codes starting with 4 are temporary errors - Postfix will retry to deliver the email. Codes starting with 5 are permanent errors and Postfix will instantly bounce the email and inform the sender of the delivery failure. Codes starting with 2 are successes.

If the delivery was successful the "postfix/smtp" line will look like this:

Jun  5 12:41:10 mail postfix/smtp[12044]: 2171CA860E0: to=<jonathan@example.com>, relay=mx.example.com[191.13.14.2]:25, delay=0.32, delays=0.04/0/0.17/0.1, dsn=2.0.0,
 status=sent (250 2.0.0 Ok: queued as B0BAC736372)

The last part of the message contains a string that the remove mail server returns after the successful delivery. So if you see that an email got lost between your and the remote (mx.example.com) mail server this log line helps a lot. You see that the email was once handled in your queue as ID 2171CA860E0 and then delivered to mx.example.com which put it into its own queue as queue ID B0BAC736372. So you can try to contact the postmaster of the remote server and ask what happend to this email.

Getting statistics

Reading your mail log file barely gives you interesting information at a glance. Especially on a busy mail server you will barely get an idea what is going on except for counting the lines of the log file. I prefer to run "pflogsumm" (Postfix Log Summary) on my mail logs. You can easily install this software:

apt-get install pflogsumm

The just run this program on your log file:

pflogsumm /var/log/mail.log

What you get is general counts like:

messages

    129   received
    331   delivered
      1   forwarded
      8   deferred  (59  deferrals)
      3   bounced
    586   rejected (63%)
      0   reject warnings
      0   held
      0   discarded (0%)

   3108k  bytes received
   3967k  bytes delivered
     36   senders
     28   sending hosts/domains
    229   recipients
    147   recipient hosts/domains

as well as per-hour traffic summaries (how many emails were sent and received during what hours). You also get a sorted list of sender and recipient domains. Aside from general statistics pflogsumm also extracts errors and warnings so you get a quick overview of why emails were deferred or rejected/bounced and the effectiveness of the RBLs (real-time blacklists) that you use.

Take a look at the example cron entries in /usr/share/doc/pflogsumm/examples on your system. They help you get an automatic daily and weekly report.

Blocking script kiddies with fail2ban

You are surely aware that the internet is not the friendly place it once used to be. Fortunately most of the attackers you will face at your mail server are stupid and adventurous script kiddies. They will use dumb scripts to try a few username/password combinations to get access to mailboxes. In your /var/log/mail.log this will look like this:

dovecot: pop3-login: Disconnected (auth failed, 1 attempts): user=<mp3>, method=PLAIN, rip=61.144.24.114, lip=87.152.157.104
dovecot: pop3-login: Disconnected (auth failed, 1 attempts): user=<oscar>, method=PLAIN, rip=61.144.24.114, lip=87.152.157.104
dovecot: pop3-login: Disconnected (auth failed, 1 attempts): user=<root>, method=PLAIN, rip=61.144.24.114, lip=87.152.157.104
dovecot: pop3-login: Disconnected (auth failed, 1 attempts): user=<root>, method=PLAIN, rip=61.144.24.114, lip=87.152.157.104
dovecot: pop3-login: Disconnected (auth failed, 1 attempts): user=<root>, method=PLAIN, rip=61.144.24.114, lip=87.152.157.104
dovecot: pop3-login: Disconnected (auth failed, 1 attempts): user=<webpage>, method=PLAIN, rip=61.144.24.114, lip=87.152.157.104
dovecot: pop3-login: Disconnected (auth failed, 1 attempts): user=<webpage>, method=PLAIN, rip=61.144.24.114, lip=87.152.157.104
dovecot: pop3-login: Disconnected (auth failed, 1 attempts): user=<root>, method=PLAIN, rip=61.144.24.114, lip=87.152.157.104
dovecot: pop3-login: Disconnected (auth failed, 1 attempts): user=<root>, method=PLAIN, rip=61.144.24.114, lip=87.152.157.104
dovecot: pop3-login: Disconnected (auth failed, 1 attempts): user=<root>, method=PLAIN, rip=61.144.24.114, lip=87.152.157.104
dovecot: pop3-login: Disconnected (auth failed, 1 attempts): user=<bbuser>, method=PLAIN, rip=61.144.24.114, lip=87.152.157.104
dovecot: pop3-login: Disconnected (auth failed, 1 attempts): user=<root>, method=PLAIN, rip=61.144.24.114, lip=87.152.157.104
dovecot: pop3-login: Disconnected (auth failed, 1 attempts): user=<root>, method=PLAIN, rip=61.144.24.114, lip=87.152.157.104
dovecot: pop3-login: Disconnected (auth failed, 1 attempts): user=<telecom>, method=PLAIN, rip=61.144.24.114, lip=87.152.157.104
dovecot: pop3-login: Disconnected (auth failed, 1 attempts): user=<root>, method=PLAIN, rip=61.144.24.114, lip=87.152.157.104
dovecot: pop3-login: Disconnected (auth failed, 1 attempts): user=<dbadmin>, method=PLAIN, rip=61.144.24.114, lip=87.152.157.104

We are not using user names like "oscar" but rather "oscar@example.com" so this embarrassing attempt will not work anyway. But why take the chance? We can use the "fail2ban" software to deal with brute force attacks like this easily. First install the fail2ban software on your server:

apt-get install fail2ban

Fail2ban starts a daemon process that can watch various log files, look for certain attack patterns there (defined by regular expressions) and act accordingly. We can teach fail2ban to look for "auth failed" lines like above and add a firewall rule (using iptables by default) to block access from the kid's IP address. By default fail2ban will run such a blocking action it it finds three attack attempts within ten minutes and will then block the attacker for ten minutes. These values are configurable.

Add a file "/etc/fail2ban/filter.d/dovecot-pop3imap.conf" containing:

[Definition]
failregex = (?: pop3-login|imap-login): .*(?:Authentication failure|Aborted login \(auth failed|Aborted login \(tried to use disabled|Disconnected \(auth failed).*rip=(?P<host>\S*),.*
ignoreregex =

This adds a regular expression telling fail2ban what a failed login attempt looks like. The P<host> part at "rip" (remote IP) will contain the respective IP address of the attacker. fail2ban passes it to the blocking action to ban this very IP address.

Then edit the "/etc/fail2ban/jail.conf" file. First enable the "postfix" part that is disabled by default:

[postfix]
enabled  = true
port     = smtp,ssmtp
filter   = postfix
logpath  = /var/log/mail.log

Also add a section for the Dovecot configuration you added earlier.

[dovecot-pop3imap]
enabled = true
port = pop3,pop3s,imap,imaps
filter = dovecot-pop3imap
logpath = /var/log/mail.log

Restart fail2ban:

/etc/init.d/fail2ban restart

Now you can wait for kids to try their luck. But to check that everything works you can also fake an attack by sending manually crafted log entries:

logger -p mail.info -t dovecot "imap-login: Aborted login (auth failed, 2 attempts): user=<hanswaltergeorgfoo>, method=PLAIN, rip=10.20.30.40, lip=1.2.3.4, TLS"

Run the above command three times so that fail2ban triggers its action. If everything went as desires then your /var/log/fail2ban.log will read:

fail2ban.actions: WARNING [dovecot-pop3imap] Ban 10.20.30.40

Now attackers can do no more than three attacks within ten minutes. Nice, isn't it?

21 Comments

fail2ban to limit spammers

Hi,

I am using RBL lists to reduce the amount of spam I get. One thing I noticed when looking at the logs is that I would often see lots of spam attempts from the same host, all of which would be rejected with an RBL log entry. Just today, I had one spam-server trying more than 300 times in just an hour to send me e-mail - all of which were blocked, of course.

So I thought - why not use fail2ban to lock out the spammers? Just as you can ban script kiddies trying to brute-force passwords, you can use it to block repeated spam-attempts. After some experimenting I came up with this configuration:

1) Create /etc/fail2ban/filter.d/postfixrbl.conf :
[Definition]
failregex = NOQUEUE: reject: RCPT from .*\[<HOST>\]: 554 5.7.1 Service unavailable; Client host \[[0-9.]+\] blocked using
ignoreregex =
 

2) Add this to /etc/fail2ban/jail.local :

[postfixrbl]
enabled = true
port = smtp
filter = postfixrbl
logpath = /var/log/mail.info
bantime = 86400
action = %(action_mw)s
 

Then run "/etc/init.d/fail2ban reload" to reload the configuration (or 'fail2ban-client reload').

I've increased the "bantime" to 24 hours, since RBL removals don't happen quickly. I'll have to watch it for some time to see how large the ban-list gets, but it seems to work quite nicely.

 

Regards,

Henrik

PS: about the "action" setting

The action-line will make fail2ban send you an email whenever an IP is put into the jail. Good for debugging, or to rejoice over your effective spam-filtering :-) If you don't want to see these, just remove the "action = ..." line.

Henrik

Re: fail2ban to limit spammers

This is very useful, I just wanted to point out that the delivery attempts your filter aims at are also caught by the standard postfix filter delivered with fail2ban.
Unless you really want both actions to be triggered be sure to also add a corresponding exclude statement to the standard postfix filter if you have it activated.

Also if you are not really tied down for bandwidth / performance, I would suggest REJECTing these connection attempts instead of simply dropping them. Apart from being more standard compliant, the additional resource usage is minimal, and it will greatly ease debugging should a legitimate mail server ever happen to get blacklisted by accident. Most legitimate mail servers interpret a timeout as an unspecified temporary malfunction when informing the user or just try again, whereas a reject is seen as a decisive administrative action which usually triggers a much more informative message to the user. Spammers on the other hand usually don't evaluate the response at all and just move on, so this is purely informative.

I am aware however, that this is a somewhat religious topic. Decide for yourself.

Logging fixes on Ubuntu

Just a helpful hint for those installing on Ubuntu Server 10.04, rsyslog is automatically set to reduce the log output by compressing recurrent messages, which breaks the fail2ban mechanism. Therefore, changing this in /etc/rsyslog.conf is vital:

sed -i `s/RepeatedMsgReduction\ on/RepeatedMsgReduction\ off/` /etc/rsyslog.confservice fail2ban restart && service rsyslog restart

Thanks go to http://www.grosseosterhues.com for the tip.

Fail2ban - any advice please?

On reading your tutorial, fail2ban looked quite easy to implement, but I'm not getting any result on testing.

This is my filter file, which is copied and pasted directly from here:

[Defintion]
failregex = (?: pop3-login|imap-login): .*(?:Authentication failure|Aborted login \(auth failed|Aborted login \(tried to use disabled|Disconnected \(auth failed).*rip=(?P<host>\S*),.*
ignoreregex =

Here's my jail.conf section which I believe to be correct:

#
# Mail servers
#

[postfix]

enabled  = true
port     = smtp,ssmtp
filter   = postfix
logpath  = /var/log/mail.log

[dovecot-pop3imap]

enabled = true
port = pop3,pop3s,imap,imaps
filter = dovecot-pop3imap
logpath = /var/log/mail.log
 

And finally, having restarted fail2ban, here's my fail2ban.log output after using your command three times (I simply copied and pasted the command into a terminal and ran it, which I believe to be correct):

2011-09-26 01:53:33,019 fail2ban.server : INFO   Changed logging target to /var/log/fail2ban.log for Fail2ban v0.8.4-SVN
2011-09-26 01:53:33,020 fail2ban.jail   : INFO   Creating new jail 'dovecot-pop3imap'
2011-09-26 01:53:33,020 fail2ban.jail   : INFO   Jail 'dovecot-pop3imap' uses poller
2011-09-26 01:53:33,036 fail2ban.filter : INFO   Added logfile = /var/log/mail.log
2011-09-26 01:53:33,037 fail2ban.filter : INFO   Set maxRetry = 3
2011-09-26 01:53:33,037 fail2ban.filter : INFO   Set findtime = 600
2011-09-26 01:53:33,038 fail2ban.actions: INFO   Set banTime = 600
2011-09-26 01:53:33,041 fail2ban.jail   : INFO   Creating new jail 'ssh'
2011-09-26 01:53:33,041 fail2ban.jail   : INFO   Jail 'ssh' uses poller
2011-09-26 01:53:33,042 fail2ban.filter : INFO   Added logfile = /var/log/auth.log
2011-09-26 01:53:33,043 fail2ban.filter : INFO   Set maxRetry = 6
2011-09-26 01:53:33,043 fail2ban.filter : INFO   Set findtime = 600
2011-09-26 01:53:33,044 fail2ban.actions: INFO   Set banTime = 600
2011-09-26 01:53:33,095 fail2ban.jail   : INFO   Creating new jail 'postfix'
2011-09-26 01:53:33,095 fail2ban.jail   : INFO   Jail 'postfix' uses poller
2011-09-26 01:53:33,096 fail2ban.filter : INFO   Added logfile = /var/log/mail.log
2011-09-26 01:53:33,097 fail2ban.filter : INFO   Set maxRetry = 3
2011-09-26 01:53:33,098 fail2ban.filter : INFO   Set findtime = 600
2011-09-26 01:53:33,098 fail2ban.actions: INFO   Set banTime = 600
2011-09-26 01:53:33,103 fail2ban.jail   : INFO   Jail 'dovecot-pop3imap' started
2011-09-26 01:53:33,107 fail2ban.jail   : INFO   Jail 'ssh' started
2011-09-26 01:53:33,111 fail2ban.jail   : INFO   Jail 'postfix' started

No mention of ; fail2ban actions: WARNING [dovecot-pop3imap] Ban 10.20.30.40 in spite of running the command multiple times. My mail.log shows the connection being rejected. Is that significant or can anyone see a glaring eror that I've missed please? I have to admit I'm at a loss to understand why I'm not getting the expected result.

Solved.

OK, I fully expected to investigate this problem further tonight and started by looking at the fail2ban.log file.

Surprise, surprise, it blocked two attempts today from China and the USA, so it appears, it's working as advertised.

The only issue seems to be Christophs manually crafted entries, will not work on my server (for whatever reason). That's certainly not the end of the world, but one that others should be aware of, just in case they get the same false impression.

Thanks you Christoph, for undoubtedly, the best documentation I've ever seen for setting up an email server - superb.

confirmed

a little bit of more digging: testing with fail2ban-regex gives a positive match.

fail2ban-regex "Jan 21 05:41:25 (none) dovecot: imap-login: Disconnected (auth failed, 2 attempts): user=<hanswaltergeorgfoo>, method=PLAIN, rip=10.20.30.40, lip=1.2.3.4, TLS" "(?: pop3-login|imap-login): .*(?:Authentication failure|Aborted login|Disconnected).*rip=(?P<host>\S*),.*"

bash administration cli tool

I've wrote a cli tool in bash that I've used and tested in production for managing the database and the file system.

You can check it here:

https://github.com/zanshine/postadmin

It's database and (partialy) schema agnostic and highly configurable. The code is quite straight forward, so you should be able to customize it to suit your need if it's don't out of the box.

quota

Saw you mentioned quota on the previous version.  But not on this version.  I thought I'd use the previous documentation but looks like the plugins have changed for dovecot version 2.x.

Dovecot 1.x:

protocol imap {
  mail_plugins = quota imap_quota
}
protocol pop3 {
  mail_plugins = quota
}
# In case you're using deliver:
protocol lda {
  mail_plugins = quota
} 

Dovecot 2.x

Enable them in configuration files, e.g.:

conf.d/10-mail.conf:

# Space separated list of plugins to load for all services. Plugins specific to
# IMAP, LDA, etc. are added to this list in their own .conf files.
mail_plugins = $mail_plugins quota

conf.d/20-imap.conf:

protocol imap {
  # Space separated list of plugins to load (default is global mail_plugins).
  mail_plugins = $mail_plugins imap_quota
}

Am I missing something? Any chance of a document update.  Great job overall though.

thunderbird client

Tried to set up  a thunderbird client.  Not having much luck. (I'm a little new to all this.)  Perhaps you could add a short section on how to set up thunderbird sometime in the future :)  Perhaps others might be interested.  Thanks for the tutorials.

Does anyone know..

how to set up an auto reply for multiple vmail email addresses and domains?

In other words, so the response message can be tailored for each individual user.

What I'm lookng for is a simple auto reply along the lines of; "Thank you for your message, we'll reply as soon as we can".

I've searched for a while, but I'm having problems understanding, where in the chain, an auto reply would sit. Is it in Postfix, Dovecot or Roundcube and is there any recommended application that works with this setup please?

Backing up ISPmail

I'm wondering if this topic has been covered before but I cant find it anywhere.
Can you please explain how to properly backup this server?
Perhaps I can recommend this for an additional tutorial?

One way I am thinking of is to prepare an image of the whole system using programs such as Remastersys and then use backup tools such as rbackup to backup the email data.
But I read somewhere that this will not work since the metadata is not copied (privileges, timestamp, etc).
Also, other components of it need to be backed up, such as the mysql db of user and domain info.

But I dont know exactly, for sure, which ones to be backed up and how to do it.

Thanks Christoph

backing up the software and os may be important too

Awesome, Christoph.
An additional issue is to actually backup the software so in case of problems we can just install for bare metal recovery.
A problem in mind is the different config setup needed for upgraded software (most recent one I found was postfix). So it is preferrable to also backup the os and software to speed up recovery.

Backing up

Personally, I use clonezilla once a week to make an image of the whole server drive. My method is to synchronise my standby server (with the main server) and then put the standby on-line. I then take the main server off-line and make the image. It's relatively small and the whole operation including updating the main server (at this point, I have a real time image I just made to recover it if needed), takes about 25 minutes.

Any problems in the interim can be dealt with as I also use Christoph's excellent method of backing up to a USB drive for the incrementals. See his Linux section for more details. In addition I run a cron job for the database dumps. So there's very little work that isn't automated.

I actually had a RAID failure about a year ago, which failed to restore and I was very grateful for my images.

Don't think it won't happen to you - it will!

Maybe its important to backup

Maybe its important to backup too:

- mySQL user(s) to access the database(s): vmail, roundcube, sqlgrey, policyd, amavis...
- amavis: /etc/amavis
- amavis: (+virusmails) /var/lib/amavis
- postfix queue: /var/spool/postfix
- /usr/local/sbin -> your (cron) scripts
- /etc/passwd
- /etc/groups

...backing up the /etc directory should be a good idea!