I've been running my own personal mail server for almost two years. On Friday May 15, I tried to send an email and immediately received a undeliverable mail response from my mail server.
This is the mail system at host tarnbarford.net.
I'm sorry to have to inform you that your message could not
be delivered to one or more recipients. It's attached below.
For further assistance, please send mail to postmaster.
If you do so, please include this problem report. You can
delete your own text from the attached returned message.
The mail system
<xxxxxxxx@xxxxxxxx>: host gmail-smtp-in.l.google.com[74.125.136.26] said:
550-5.7.1 [144.76.187.44 12] Our system has detected that this message
is 550-5.7.1 likely unsolicited mail. To reduce the amount of spam sent to
Gmail, 550-5.7.1 this message has been blocked. Please visit 550-5.7.1
http://support.google.com/mail/bin/answer.py?hl=en&answer=188131 for 550
5.7.1 more information. y7si5709303wjw.181 - gsmtp (in reply to end of DATA
command)
A week earlier a friend told me that one of my mails had been marked as spam by GMail, which was concerning, but I figured maybe I could take some steps to ensure my mail server looked more legitimate, like setting up reverse DNS lookup, SPF and DKIM correctly. This seemed much more concerning. I took a break outside to think about and what I should do next and why Google was picking on me all of a sudden? Slowly it dawned on me that maybe my server had been compromised.
I rushed back to my computer, shelled into the server and ran tail -f on the
mail log. I was immediately presented a continuous stream of log messages.
Fuck. I stopped the tail to see what was happening, it didn't look good
"delivery temporarily suspended", "ERROR: Mail Refused", "Retrying will NOT
succeed.". I stopped postfix and re-ran the tail command, the tail of log
appeared but thankfully new log messages were not appearing.
"Table tennis?" a colleague had approached me from behind and shocked me. "Not now, I'm busy" I snapped back, shocking him and me. I broke my trance like stare from the shell on my screen, turned around and explained that my mail server had been compromised and appeared to by trying to send spam.
I turned back to my computer to see a message from Michal, we share a physical server which we run virtual machines on using KVM. "Hey", this cannot have been unrelated so I beat him to the punch, "my server was spamming :'(". He'd received an abuse email from our hosting provider.
15:41:48 piwoni: hey
15:41:54 tarnacious: yes?
15:42:05 tarnacious: my server was spamming :'(
15:42:09 piwoni: yes
15:42:14 tarnacious: I don't know how
15:42:16 piwoni: wanted to tell you
15:42:19 tarnacious: thanks
15:42:22 tarnacious: too late
15:42:44 tarnacious: you get email from hetzner?
15:42:45 tarnacious: :D
15:42:49 piwoni: yes
15:42:53 tarnacious: today?
15:42:55 piwoni: yes
15:42:58 tarnacious: ok.
15:43:05 tarnacious: has been 4 days.
15:43:11 tarnacious: ip address is ruined :(
15:43:33 piwoni: how did it happen?
15:43:42 tarnacious: I don't know yet.
15:43:45 piwoni: ok
15:44:05 piwoni: do you have anyting on your
15:44:08 piwoni: site?
15:44:13 piwoni: form?
15:44:36 tarnacious: nope.
15:44:37 piwoni: is the smtp with auth
15:44:45 tarnacious: yep.
15:44:56 tarnacious: maybe brute force the auth
15:45:10 tarnacious: I do not know yet.
15:45:49 tarnacious: queue was pretty massive, but most mail servers have stopped talking to me.
I still hadn't worked out how my server had been compromised. I've been running
it for almost two years and I was pretty confident it wasn't an open relay. I
looked through the logs and found a message from android@tarnbarford.net. I
ran grep from= /var/log/mail.log, this account was trying to send a lot of
mail.
15:51:43 tarnacious: ok, i see what has happened :(
15:51:49 piwoni: ?
15:52:39 tarnacious: in my mail logs...
15:52:47 tarnacious: sasl_username=android connects.
15:52:51 tarnacious: and me.
15:53:06 piwoni: android?
15:53:11 piwoni: username
15:53:11 piwoni: :P
15:53:17 tarnacious: android is an account I created to build android.
15:53:21 piwoni: heh
15:53:25 piwoni: and pass ?
15:53:28 tarnacious: I guess I must have given him a week password.
15:53:29 piwoni: empty ?
15:53:53 piwoni: how do you store them ?
15:54:57 tarnacious: unix password
15:55:13 piwoni: change it
15:56:44 tarnacious: no shit
I use this machine for many other things including; a web server, a VPN server, a git server, for connecting to IRC servers, for pair programming, and for running arbitrary long running processes. I try to manage the system like I think a Unix system administer would; I create user accounts for everything, I care about file permissions and try to run a much as possible as non-privileged users.
The android account was created for building a custom CyanogenMod.
Aside from taking ages to build, it also requires significantly more disk space
than I can free on my Macbook Air. As the user was not in the sudoers file
and password SSH connections are not allowed, I hadn't thought the password was
very important and presumably created an extremely weak one.
What I had not thought of was that the password could be used to authenticate with the SMTP server, this is because I have postfix set-up to use Linux accounts as users. It appeared that someone had managed to guess a username/password combination on the SMTP server. A friend later joked that the attacker may have been surprised to get access so early in their dictionary attack.
I changed the android users password, cleared the entire postfix mail queue,
restarted postfix and watched the logs. There were a few intermittent failed
login attempts, but the server didn't seem to be trying to send any more mail.
Feeling like I had done enough to temporarily safely start running the server again while still keeping an eye on the logs I moved onto working out what had happened. For this I had copied all the logs to a working directory and unzipped them. I had logs from April 19th to May 17th, 12GB in total, which itself was pretty ominous.
I initially attempted to analyse the logs myself with some awk scripts but
found the postfix logs quite difficult to extract useful summaries from. The
problem is there can be many log entries for a single message and useful
information is spread across them. There is some sort of ID in each log message
and I initially thought that the ID would be unique per message and I could
group on that and work out what happened for each ID, but it turns out it is a
little more complicated than that as messages can have multiple recipients.
Probably worth looking around, surely someone has solved the problem.
After a quick search I found a script, pflogsumm.pl, that seemed to summarise the type of information I was looking for. I'm not sure how accurate it is or what these numbers mean, but it is very clear that my little mail server had been quite busy.
Grand Totals
------------
messages
493404 received
1543k delivered
0 forwarded
311685 deferred (33608k deferrals)
448708 bounced
486 rejected (0%)
0 reject warnings
0 held
0 discarded (0%)
2406m bytes received
5826m bytes delivered
672 senders
1166 sending hosts/domains
1053k recipients
105817 recipient hosts/domains
The per day traffic summary was quite interesting to me as I shows that the account had been compromised a few weeks earlier than I thought. I also find the usage patterns quite interesting, it looks like it was compromised on April 26 and a few thousand emails were sent, possibly to test if the server could be used to send spam. Then it is used in bursts, with no email at been sent between May 7 and May 9.
Per-Day Traffic Summary
-----------------------
date received delivered deferred bounced rejected
--------------------------------------------------------------------
Apr 19 2015 21 21 0 0 12
Apr 20 2015 35 35 0 0 30
Apr 21 2015 32 32 0 0 14
Apr 22 2015 30 30 0 0 44
Apr 23 2015 34 34 0 0 8
Apr 24 2015 28 28 0 0 13
Apr 25 2015 22 22 0 0 10
Apr 26 2015 110 2030 0 2039 9
Apr 27 2015 61 60 0 0 18
Apr 28 2015 67547 193033 565k 52301 15
Apr 29 2015 149 11711 453347 10425 21
Apr 30 2015 136912 460833 1244k 90682 17
May 1 2015 11679 194702 4523k 26787 15
May 2 2015 113 10189 3798k 2113 10
May 3 2015 69 7538 3601k 850 9
May 4 2015 44 5902 3344k 6094 10
May 5 2015 109 19998 3064k 64 14
May 6 2015 63 7587 187980 0 9
May 7 2015 52 54 43 0 18
May 8 2015 65 64 21 0 17
May 9 2015 50 50 21 0 27
May 10 2015 35576 74756 335577 22229 14
May 11 2015 48658 125790 668k 68149 22
May 12 2015 88920 203938 3024k 115446 26
May 13 2015 73 5227 3056k 11819 13
May 14 2015 76 3157 2885k 6634 13
May 15 2015 102763 253975 2876k 33070 12
May 16 2015 48 48 0 3 30
May 17 2015 65 65 0 3 16
The top domains is pretty uninteresting, except that I can clearly see why GMail decided to start blocking emails from me.
Host/Domain Summary: Message Delivery
--------------------------------------
sent cnt bytes defers avg dly max dly host/domain
-------- ------- ------- ------- ------- -----------
281109 1116m 1540k 4.8 h 87.7 h hotmail.com
247760 705m 15277k 13.1 h 121.2 h yahoo.com
152088 1129m 0 1.2 m 4.9 h tarnbarford.net
118590 371368k 132586 5.3 h 120.9 h gmail.com
40608 130322k 359555 2.5 h 37.5 h aol.com
35961 132388k 1 2.8 h 15.5 h telenet.be
23607 73362k 12 7.3 h 17.3 h 163.com
21060 77012k 206635 11.9 h 120.8 h skynet.be
18418 73872k 481938 25.0 h 76.2 h hanmail.net
17039 61274k 88959 4.4 h 82.1 h msn.com
15737 57300k 62322 5.4 h 15.5 h live.nl
13636 42315k 9 6.2 h 17.3 h 126.com
13020 34618k 58867 6.9 h 21.1 h ameritech.net
11876 36937k 95879 10.5 h 77.1 h vip.sina.com
11828 30012k 1176k 8.0 h 121.1 h adelphia.net
11168 40958k 38749 5.1 h 31.7 h hotmail.fr
10203 33512k 267776 15.7 h 120.9 h yahoo.fr
9005 29039k 0 6.8 h 17.3 h sina.com
These are the top two recipients, the next ten are genuine and then a huge list of addresses used three or less times.
Recipients by message count
---------------------------
150742 android@tarnbarford.net
34696 ppway2323@hotmail.com
I have no idea why ppway2323@hotmail.com was sent so many emails and I also
don't know where the 150742 emails to android@tarnbarford.net are. There are
only 87 emails in the Maildir of the user, they are all delivery status
notifications. Usually the delivery status emails contain the original email,
so we get some information on what was sent. They are not all the same, but
they are all spam, this one is quite common.
Subject: Re: Part time job opportunity
To: Recipients <android@tarnbarford.net>
From: android@tarnbarford.net
Date: Thu, 14 May 2015 15:49:24 -0700
Reply-To: tinagerardi9470@gmail.com
Our Ref: Bny/23/9swd/34
Your Ref: ABWN/NYT/87E3
Position: Retail Product Research Coordinator.
We are a reputable Survey Company handling products and services survey
evaluation for most Fortune 500 companies in the United States of America. We
are seeking Dedicated Part time staff for the position of Retail Product
Research Coordinator. You will work as a team to test products pricing and
product display in your Geographical Zone.It is probationary assignments that
will last 18 months.Your basic pay per assignment will be $900.00. You will be
entitled to a pay review after 90 days. You only need 1hr in a day to carry out
your assignment. If interested in this position please send your reply to
tinagerardi9470@gmail.com. Include your full name, Address and a Day time
Telephone number. We will send you a package with your first Assignment as soon
as we we hear from you.
Sincerely; Tina Gerardi.
Survey Coordinator.
My initial thoughts were to build a new mail server on its own machine, I had wanted to do this anyway as the mail server was was both relatively important to me and relatively difficult to set up. If not automate the set up, I wanted to at least document it. I decided against building it now as it appeared the server itself wasn't compromised, I didn't have the time and I would probably have to deal with my host name being on email blacklists even if I changed IP address. So I decided to see if I could harden this server and get myself off the blacklists.
I immediately added smtpd_sender_restrictions to only allow mail to be
sent by specified users. Although I will probably create users with --disabled-password in the future, there are potentially other accounts on the
system with weak passwords. It was quite easy to verify this was working, I
just removed myself from the list, restarted postfix and tried to send a mail.
$ cat mail.eml | msmtp -a tarn tarn.barford@retresco.de
msmtp: recipient address tarn.barford@retresco.de not accepted by the server
msmtp: server message: 554 5.7.1 <tarn@tarnbarford.net>: Sender address rejected: Access denied
msmtp: could not send mail (account tarn from /Users/tarn/.msmtprc)
I enabled fail2ban jails for postfix and sasl which means any IP
address that fails to authenticate 3 times will be banned for an hour. This was
just a matter of enabling some sections in the fail2ban configuration as
I already had it running for ssh connections. I found out this works the hard
way by accidentally banning myself while testing other SMTP logins failed.
I used policyd to setup per-address rate limiting for sending and
receiving mail. This was a bit more tricky, but I found a guide that
helped me get it set-up. I tested this works by setting the quota really low
and sending a few messages.
$ cat mail.eml | msmtp -a tarn tarn.barford@retresco.de
$ cat mail.eml | msmtp -a tarn tarn.barford@retresco.de
$ cat mail.eml | msmtp -a tarn tarn.barford@retresco.de
$ cat mail.eml | msmtp -a tarn tarn.barford@retresco.de
msmtp: recipient address tarn.barford@retresco.de not accepted by the server
msmtp: server message: 554 5.7.1 <tarn@tarnbarford.net>: Sender address rejected: Sender quota exceed.
msmtp: could not send mail (account tarn from /Users/tarn/.msmtprc)
Setting up a Sender Policy Framework (SPF) is just a matter setting a
TXT record on the domain name.
$ dig +short -t txt tarnbarford.net
"v=spf1 mx a -all"
In my case all mail from my domain should come from the IP that is in the
MX record, and if not then it should be rejected.
To send DomainKeys Identified Mail (DKIM) you need to create a key-pair,
publish the public key as a domain record and add a header each email with a
signature of the contents. There is a Debian package for OpenDKIM that
includes a daemon that can sign mails and is easy to integrate with
Postfix. Below is an example of a DKIM signed message I sent to myself.
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=tarnbarford.net;
s=mail; t=1432809266;
bh=YocFhtTgjr2exNi9eb3SUWb8spcRxFH1Tqh/0OcRcfA=;
h=Date:From:To:Subject:From;
b=PAy0LzlmVsAQaQ9NzI4d+RSLMpz8Fg/eqNrVYU9rFlc7WHnIkBwBpFol2NQy8T+yg
Dxuw3OAjDh0kjV7W9LF0Y2rnjVfVJ5RLQRVe0HJiVOkLyS9cESoZZ63Ki4uUb/oB8N
hhvWPjrKw6hukPZYGSCOhGg8Zz8da1EviMHB6oP4=
Date: Thu, 28 May 2015 12:34:24 +0200
From: Tarn Barford <tarn@tarnbarford.net>
To: tarn@tarnbarford.net
Subject: DKIM
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
User-Agent: Mutt/1.5.23 (2014-03-12)
hello, DKIM.
My DKIM public key for this message can be found based on the from header and
the s field in the DKIM signature.
$ dig +short -t txt mail._domainkey.tarnbarford.net
"v=DKIM1\; k=rsa\; p=MIGfMA0GCSqGSIb3DQEBAQUAA4GNADCBiQKBgQC0LNf8wdRCk2eXt1+EAIAdDSfq4aLMR/a6hCdPzJdAZ5OB1Z2LvOJlUGtx81MAttOG2lztjMmdrEq4mmGe0LUXOmOTqMcY8/woNspqvj9N4zPUEZXFP6yrYlgVGuVcLYWV6huCviwlt49KciaB9al+E2PogZJxDda5/cYffrI4PQIDAQAB"
There are plenty of tools to create and validate DKIM mail signatures including a Python library. This validated that my DKIM signature was valid for the above mail.
$ virtualenv .
$ ./bin/pip install dkimpy
$ ./bin/pip install dnspython
$ ./bin/dkimverify.py < test.eml
signature ok
While this verifies the signature is ok, I wasn't entirely satisfied and wanted
to see what was going on. The DKIM-Signature header has a body hash field
bh which is specified in the header as being an rsa-sha256 hash. Once this
is verified the signature itself can be verified on the headers alone as the
headers contain a hash of the body contents.
$ printf "hello, DKIM.\r\n" | openssl dgst -binary -sha256 | openssl base64
YocFhtTgjr2exNi9eb3SUWb8spcRxFH1Tqh/0OcRcfA=
This matches the body hash in the signature, so we can continue. To verify the authenticity of this mails headers a signature, a public key and the exact headers that were signed with the private key are required.
The b field in the DKIM-Signature header is the signature. It is base64
encoded and openssl requires the binary form, so it needs to be decoded and
saved.
$ printf "PAy0LzlmVsAQaQ9NzI4d+RSLMpz8Fg/eqNrVYU9rFlc7WHnIkBwBpFol2NQy8T+ygDxuw3OAjDh0kjV7W9LF0Y2rnjVfVJ5RLQRVe0HJiVOkLyS9cESoZZ63Ki4uUb/oB8NhhvWPjrKw6hukPZYGSCOhGg8Zz8da1EviMHB6oP4=" | openssl enc -base64 -d -A > signature
The p field in the mail._domainkey is a base64 encoded, DER encoded
public key.
$ printf "MIGfMA0GCSqGSIb3DQEBAQUAA4GNADCBiQKBgQC0LNf8wdRCk2eXt1+EAIAdDSfq4aLMR/a6hCdPzJdAZ5OB1Z2LvOJlUGtx81MAttOG2lztjMmdrEq4mmGe0LUXOmOTqMcY8/woNspqvj9N4zPUEZXFP6yrYlgVGuVcLYWV6huCviwlt49KciaB9al+E2PogZJxDda5/cYffrI4PQIDAQAB" | openssl enc -base64 -d -A > key.der
This can be verified this by converting it back into a familiar looking public
key and saving it as key.pub.
$ openssl rsa -pubin -inform DER < key.derwriting RSA key | tee key.pub
writing RSA key
-----BEGIN PUBLIC KEY-----
MIGfMA0GCSqGSIb3DQEBAQUAA4GNADCBiQKBgQC0LNf8wdRCk2eXt1+EAIAdDSfq
4aLMR/a6hCdPzJdAZ5OB1Z2LvOJlUGtx81MAttOG2lztjMmdrEq4mmGe0LUXOmOT
qMcY8/woNspqvj9N4zPUEZXFP6yrYlgVGuVcLYWV6huCviwlt49KciaB9al+E2Po
gZJxDda5/cYffrI4PQIDAQAB
-----END PUBLIC KEY-----
The modulus and exponent of this public key can also be checked and should be rejected if it isn't long enough.
$ openssl rsa -noout -text -pubin < key.pub
Modulus (1024 bit):
00:b4:2c:d7:fc:c1:d4:42:93:67:97:b7:5f:84:00:
80:1d:0d:27:ea:e1:a2:cc:47:f6:ba:84:27:4f:cc:
97:40:67:93:81:d5:9d:8b:bc:e2:65:50:6b:71:f3:
53:00:b6:d3:86:da:5c:ed:8c:c9:9d:ac:4a:b8:9a:
61:9e:d0:b5:17:3a:63:93:a8:c7:18:f3:fc:28:36:
ca:6a:be:3f:4d:e3:33:d4:11:95:c5:3f:ac:ab:62:
58:15:1a:e5:5c:2d:85:95:ea:1b:82:be:2c:25:b7:
8f:4a:72:26:81:f5:a9:7e:13:63:e8:81:92:71:0d:
d6:b9:fd:c6:1f:7e:b2:38:3d
Exponent: 65537 (0x10001)
The DKIM-Signature also specifies a list of headers in the h field. These
are the headers, followed by the DKIM-Signature header itself minus the
signature field b that are hashed and then signed. There are some rules about
formatting these headers before they are signed; line wrapping must be removed,
the header key and value are separated by a single colon without spaces and
headers are separated with a Carriage Return and Line Feed.
$ printf "date:Thu, 28 May 2015 12:34:24 +0200\r\n" > headers
$ printf "from:Tarn Barford <tarn@tarnbarford.net>\r\n" >> headers
$ printf "to:tarn@tarnbarford.net\r\n" >> headers
$ printf "subject:DKIM\r\ndkim-signature:v=1; a=rsa-sha256; c=relaxed/simple; d=tarnbarford.net; s=mail; t=1432809266; bh=YocFhtTgjr2exNi9eb3SUWb8spcRxFH1Tqh/0OcRcfA=; h=Date:From:To:Subject:From; b=" >> headers
Now openssl can again be used, this time to verify the key, the signature and
the headers.
$ openssl dgst -sha256 -verify key.der -keyform DER -signature signature headers
Verified OK
Great, it verifies as expected. There is obviously more detail in the RFCs or by looking at an open source implementation, but I found it interesting to see how it worked for one email.
A Domain-based Message Authentication, Reporting and Conformance (DMARC) policy is simply another DNS record that allows a domain to specify what action other mail servers should take with mail purportedly from this domain based on the combined results of SPF and DKIM checks (allow, reject, hold, etc). It also provides an email address for participating mail servers to send reports.
$ dig +short -t txt _dmarc.tarnbarford.net
"v=DMARC1\;p=reject\;pct=100\;rua=mailto:postmaster@tarnbarford.net"
My DMARC policy says to reject 100% of mails that fail either SPF or DKIM
checks and mail conformance information to postmaster@tarnbarford.net. I now
get digest DMARC reports from participating mail servers, here is what Google
sent me.
<?xml version="1.0" encoding="UTF-8" ?>
<feedback>
<report_metadata>
<org_name>google.com</org_name>
<email>noreply-dmarc-support@google.com</email>
<extra_contact_info>https://support.google.com/a/answer/2466580</extra_contact_info>
<report_id>12005498305772839030</report_id>
<date_range>
<begin>1432684800</begin>
<end>1432771199</end>
</date_range>
</report_metadata>
<policy_published>
<domain>tarnbarford.net</domain>
<adkim>r</adkim>
<aspf>r</aspf>
<p>reject</p>
<sp>reject</sp>
<pct>100</pct>
</policy_published>
<record>
<row>
<source_ip>144.76.187.44</source_ip>
<count>1</count>
<policy_evaluated>
<disposition>none</disposition>
<dkim>pass</dkim>
<spf>pass</spf>
</policy_evaluated>
</row>
<identifiers>
<header_from>tarnbarford.net</header_from>
</identifiers>
<auth_results>
<spf>
<domain>tarnbarford.net</domain>
<result>pass</result>
</spf>
</auth_results>
</record>
</feedback>
I found MXToolbox which checks a domain or IP address against quite a few email blacklists. It is quite useful as it also provides some information and links to get your IP off each list. My IP was listed in eight blacklists, I was able to get it off six almost immediately by following the delisting procedures. I believe I was on the other two remaining lists already as our other IP addresses in the network are also on the list, and are not even mail servers.
Google has been more difficult, "How to Remove Your IP from the Gmail Blacklist" goes into some detail and links to a Google Support page where you can submit delivery issues. The post says it will take 3-7 days to process provided you fixed the reason it was blocked in the first place. I filled the form out a few weeks ago after stopping the spamming and adding the sending restrictions. I thought I had done enough at that stage to be unblocked, but apparently Google didn't think so as I am still blocked. I have since added SPF, DKIM, DMARC and rate limiting and I will fill the form out again after I post this story.
This story shouldn't be seen as a reason not to run your own mail server, if you want to you should, it's fun! This was a pretty embarrassing security failure, but the exploit was crude and relatively harmless. In working out what happened and putting systems in place to prevent it occurring again I have learned a lot and added a range of anti-spam and security features to my little mail server.
Hopefully soon I will again be able to mail Google addresses, I will update this post when this happens (or doesn't).
Update June 19, 2014: I never actually re-sent that request to Google to unblock me, but today it seems I am able to send mail to GMail accounts again. Thanks GMail!