Back to post index

Analyzing my qmail logs (plus how I tried to prevent backscatter)
Tags: [email] [spam] [qmail]
Published: 20 Jan 2015 23:14

Table of contents:


With my Linode decommissioned and all the important files retrieved, it was time to search in /var/log/ for interesting things.

As mentioned in the previous post, I noticed that my qmail instance was being used to bounce spam messages: an invalid RCPT TO field would cause a bounce message, and forged FROM or RETURN-PATH fields would cause those bounces to end up in some spam target’s mail box.

I was using qmail 1.03 from djb’s site, after verifying the downloaded checksum. Unfortunately it seems that 1.03 suffers from this backscatter problem. Either netqmail (a patch set for native qmail) or a distribution’s qmail package may have a patch to validate RCPT TO but I haven’t checked.

Note that I use opensmtpd now and it rejects mail to invalid users instantly.

what does backscatter look like?

I first noticed when I started to pay attention to qmail’s queue, after seeing suspicious remote addresses in the log files:

root@li129-126:~# /var/qmail/bin/qmail-qread
13 Nov 2014 22:17:34 GMT  #157323  2087  <>
	remote  jaxqsvhyfbmyg@hillary4president.org
13 Nov 2014 14:53:25 GMT  #157303  1402  <>
	remote  vfaoktx@inanities.com
14 Nov 2014 00:42:15 GMT  #157328  2071  <>
	remote  pfsxidki@javierbaeza.com
15 Nov 2014 00:14:32 GMT  #157191  1718  <>
	remote  blprmbqybwsyq@htclub.org
13 Nov 2014 21:49:22 GMT  #157317  1914  <>
	remote  hexudwu@fanal.info

Examining the first message:

root@li129-126:~# cat /var/qmail/queue/mess/3/157323
Received: (qmail 6021 invoked for bounce); 13 Nov 2014 22:17:34 -0000
Date: 13 Nov 2014 22:17:34 -0000
From: MAILER-DAEMON@operand.ca
To: jaxqsvhyfbmyg@hillary4president.org
Subject: failure notice

Hi. This is the qmail-send program at operand.ca.
I'm afraid I wasn't able to deliver your message to the following addresses.
This is a permanent error; I've given up. Sorry it didn't work out.

<ermayne-velasquez@operand.ca>:
Sorry, no mailbox here by that name. (#5.1.1)

--- Below this line is a copy of the message.

Return-Path: <jaxqsvhyfbmyg@hillary4president.org>
Received: (qmail 6018 invoked by uid 110); 13 Nov 2014 22:17:33 -0000
Received: from unknown (HELO 69.164.214.126) (219.140.69.122)
  by operand.ca with SMTP; 13 Nov 2014 22:17:33 -0000
Message-ID: <9143848294-TNRKQQMEYPYWGHQWZVPX@xsacgcwiu.laudyservice.com>
From: "Alva Fabre" <Fabre13@laudyservice.com>
Subject: 
To: ermayne-velasquez@operand.ca
Date: Fri, 14 Nov 2014 03:15:27 -0300
Mime-Version: 1.0
Content-Type: text/html;
Content-Transfer-Encoding: 7Bit

The above email is one example of this bounce spam: according to the lowest Received: header, it was sent straight from 219.140.69.122 to ermayne-velasquez@operand.ca, with Return-Path: <jaxqsvhyfbmyg@hillary4president.org>.

As an aside: I only received one or two spam emails that were sent to a valid address. Both were 419 scams.

log analysis

My qmail logs indicate the following:

where a spam bounce would appear in the logs as:

new msg 163610
info msg 163610: bytes 834 from <C4E7F1C@frontiersnow.com> qp 11239 uid 110
starting delivery 364: msg 163610 to local jermayne-velasquez@operand.ca
status: local 1/10 remote 0/20
delivery 364: failure: Sorry,_no_mailbox_here_by_that_name._(#5.1.1)/
status: local 0/10 remote 0/20
bounce msg 163610 qp 11242
end msg 163610
new msg 163974
info msg 163974: bytes 1384 from <> qp 11242 uid 111
starting delivery 365: msg 163974 to remote C4E7F1C@frontiersnow.com
status: local 0/10 remote 1/20
delivery 365: success: 70.87.187.178_accepted_message./Remote_host_said:_250_OK_id=1TfrNM-000857-AN/
status: local 0/10 remote 0/20
end msg 163974

When I first realized that my qmail instance was being used for backscatter, I figured that spammers would capitalize on my mistake as a naive administrator and that there would be a lot more than 179 spam bounces. I’m glad that this didn’t happen.

what I did to try and prevent backscatter

Before switching to opensmtpd, I spent some time trying to fix qmail.

use rhost-check to validate reverse dns records

Here was my /service/qmail-smtpd/run file:

exec /command/softlimit -m 4000000 \
   /usr/local/bin/tcpserver -v -R -u 110 -g 1002 -p 0 smtp \
   /usr/local/bin/rhost-check \
   /usr/local/bin/rblsmtpd \
   /var/qmail/bin/qmail-smtpd 2>&1

What happens is that each program in this list calls exec on the next, and rhost-check is a small program which instructs rblsmtpd to reject a SMTP session if the remote IP has no valid reverse DNS entry:

tcpserver: status: 1/40
tcpserver: pid 12322 from 176.56.237.217
tcpserver: ok 12322 operand.ca:69.164.214.126:25 :176.56.237.217::43163
rblsmtpd: 176.56.237.217 pid 12322: 451 bad reverse DNS
tcpserver: end 12322 status 0

Unfortunately this does not flag all bad SMTP sessions:

tcpserver: status: 1/40
tcpserver: pid 17824 from 92.49.230.221
tcpserver: ok 17824 operand.ca:69.164.214.126:25 92-49-230-221.dynamic.peoplenet.ua:92.49.230.221::4328
new msg 157184
info msg 157184: bytes 1599 from <Boden.Jordanbojik@peoplenet.ua> qp 17825 uid 110
starting delivery 230: msg 157184 to local jermayne-velasquez@operand.ca

Any ISP which provides reverse DNS entries for their customers will cause those customers to pass this check.

using libspf2 to validate sender IPs

Next, I wrote spfd, a daemon which ran as a non-priviledged user and isolated qmail-smtpd from the libspf2 library I wanted to use.

Here is what would happen:

This worked as intended:

tcpserver: status: 1/40
tcpserver: pid 14193 from 1.164.109.2
tcpserver: ok 14193 operand.ca:69.164.214.126:25 1-164-109-2.dynamic.hinet.net:1.164.109.2::40226
qmail-spf: ip <1.164.109.2> from_addr <support@microsoft.com>
qmail-spf: spf_result is SPF_RESULT_FAIL
qmail-spf: response = Received-SPF: fail (li129-126: domain of microsoft.com does not designate 
           1.164.109.2 as permitted sender) client-ip=1.164.109.2; envelope-from=support@microsoft.com;
tcpserver: end 14193 status 256
tcpserver: status: 0/40

This setup would reject mail according to properly configured and up-to-date SPF records while insulating qmail from libspf bugs.

Below is the distribution of results returned from every qmail-spf query:

     11 SPF_RESULT_FAIL
     28 SPF_RESULT_NEUTRAL
    928 SPF_RESULT_NONE
    219 SPF_RESULT_PASS
      2 SPF_RESULT_PERMERROR
      8 SPF_RESULT_SOFTFAIL

The problem is that if a domain didn’t have a SPF record then the qmail-spf query would see a NONE result, which means qmail should process the message. A NEUTRAL or SOFTFAIL would also mean that the message should be processed. Only if a FAIL was seen could the message be rejected, but only 11 SPF rejections were made, making this a non-effective spam fighting technique.

validating RCPT TO

At this point, I was looking for patches to perform RCPT TO validation, but decided to switch to opensmtpd instead. I had learned a lot through this process but didn’t want to spent much more time side tracked with this - opensmtpd is a modern secure email server that will evolve with spam techniques better than I can.