postfix疯狂外发垃圾邮件之分析与解决
本周二上班有人反应公司邮箱无法外发邮件，后来登录到服务器查看原因，不看不知道，一看吓一跳，服务器日志疯狂滚动！一看全是被其它邮件服务器拒绝的信息！由于这台服务器以前不是我管，连配置文件都find了好久，最终从十多个main.cf中找到了真正的配置文件......
下面开始分析问题与解决问题！
分析
localhost# find / -name main.cf
.......
/usr/local/etc/postfix/main.cf
/usr/opt/software/postfix-2.8.9/conf/main.cf
/etc/postfix/main.cf
这么多配置文件也不知道具体是哪个，但根据常理，最有可能的便是/etc/postfix/main.cf了。
打开/etc/postfix/main.cf来看看。
localhost# cat /etc/postfix/main.cf | grep -v # | grep -v ^$
queue_directory = /var/spool/postfix
command_directory = /usr/sbin
daemon_directory = /usr/libexec/postfix
data_directory = /var/lib/postfix
mail_owner = postfix
myhostname = mail.example.com
mydomain = example.com
myorigin = $mydomain
unknown_local_recipient_reject_code = 550
debug_peer_level = 2
debugger_command =
PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin
ddd $daemon_directory/$process_name $process_id & sleep 5
sendmail_path = /usr/sbin/sendmail
newaliases_path = /usr/bin/newaliases
mailq_path = /usr/bin/mailq
setgid_group = maildrop
html_directory = no
manpage_directory = /usr/local/man
sample_directory = /etc/postfix
message_size_limit = 512000000
virtual_mailbox_limit = 1024000000
readme_directory = /usr/local/share/doc/postfix
virtual_mailbox_base = /usr/opt/home/domains
virtual_uid_maps = static:1000
virtual_gid_maps = static:1000
virtual_alias_maps = $alias_maps, MySQL:/etc/postfix/mysql_virtual_alias_maps.cf
virtual_mailbox_maps = mysql:/etc/postfix/mysql_virtual_mailbox_maps.cf
virtual_mailbox_domains = mysql:/etc/postfix/mysql_virtual_domains_maps.cf
smtpd_sasl_auth_enable = yes
broken_sasl_auth_clients = yes
smtpd_sasl_local_domain = $myhostname
smtpd_sasl_security_options = noanonymous
smtpd_recipient_restrictions =
permit_mynetworks,
permit_sasl_authenticated,
reject_unauth_destination,
dspam_destination_recipient_limit = 1
mydestination =
smtpd_sender_restrictions = check_sender_access hash:/etc/postfix/sender_access
smtpd_client_restrictions =
reject_rbl_client cblless.anti-spam.org.cn,
reject_rbl_client cdl.anti-spam.org.cn,
reject_rbl_client opm.blitzed.org,
reject_rbl_client bl.spamcop.NET
localhost# vi /etc/postfix/sender_access
carr.chee@aol.com REJECT
Henry.bny5@hotmail.com REJECT
pmck.hsr69@yahoo.com REJECT
........
由以上配置文件可以看到，我们对发信者的检测仅限于sender_access。仅仅只是拒绝了sender_access中拒绝的用户。而没有其它任何限制。限制条件很宽松。
截取部分日志分析
localhost# tail /var/log/maillog
Oct 22 16:36:01 localhost postfix/error[18675]: 42263221CA: to=<altoact@verizon.Net>, relay=none, delay=111421, delays=105070/6348/0/2.6, dsn=4.0.0, status=deferred (delivery temporarily suspended: host relay.verizon.net[206.46.232.11] refused to talk to me: 571 Email from 124.172.224.76 is currently blocked by Verizon Online's anti-spam system. The email sender or Email Service Provider may visit http://www.verizon.net/whitelist and request removal of the block. 121022)
Oct 22 16:36:01 localhost postfix/qmgr[32357]: 184F627BF64: from=<lindawatts338@yahoo.com.hk>, size=2338, nrcpt=50 (queue active)
Oct 22 16:36:01 localhost postfix/smtp[18300]: 1C34F26235C: to=<andrew.rawson@honeywell.com>, relay=mail2.honeywell.com[199.61.24.28]:25, delay=110287, delays=110274/11/2.4/0, dsn=4.0.0, status=deferred (host mail2.honeywell.com[199.61.24.28] refused to talk to me: 554 mail2.honeywell.com)
Oct 22 16:36:01 localhost postfix/smtp[18288]: connect to news-daily.com.inbound15.mxlogicmx.net[208.65.144.12]:25: Connection refused
发现全是一些被defferred的信息。其它邮件服务器已经拒绝我们投递。
那么再用mailq命令来查看一下队列文件。
结果发现mailq刷屏刷得没完没了了。太多缓存的邮件！
localhost# mailq
-Queue ID- --Size-- ----Arrival Time---- -Sender/Recipient-------
5D1477C0D* 2333 Mon Oct 22 18:36:47 jrobert299@yahoo.com.hk
(delivery temporarily suspended: host mx.west.cox.net[68.6.19.3] refused to talk to me: 554 fed1rmimpi210 cox 124.172.224.76 blocked. Error Code: IPBL0100 - Refer to Error Codes section at http://postmaster.cox.net/confluence/display/postmaster/Error+Codes for more information.)
n_jhenderson@cox.net
截取其中一个例子来分析,可分为五部分来看。
1，5D1477C0D* 是指缓存邮件的ID
2，2333 是指邮件的大小。
3，jrobert299@yahoo.com.hk 是指发件人。
4，(delivery temporarily suspended: host mx.west.cox.net[68.6.19.3] refused to talk to me: 554 fed1rmimpi210 cox 124.172.224.76 blocked. Error Code: IPBL0100 - Refer to Error Codes section at http://postmaster.cox.net/confluence/display/postmaster/Error+Codes for more information.)
通过第4段信息我们可以得到如下信息：
delivery temporarily suspended告诉我们邮件投递被延迟。
host mx.west.cox.net[68.6.19.3] refused to talk to me 告诉我们投递给mx.west.cox.net[68.6.19.3] 的邮件服务器拒收我们的信件。
124.172.224.76 我们邮件服务器的Ip地址。
Error Code: IPBL0100 - Refer to Error Codes section at http://postmaster.cox.net/confluence/display/postmaster/Error+Codes for more information.)
通过http://postmaster.cox.net/confluence/display/postmaster/Error+Codes 上查看更多拒收的原因。
5，n_jhenderson@cox.net 收件人地址！
由上面的日志我们可以知道
1，我们的邮件服务器的发件人地址被伪造了！
2，我们邮件服务器已经被很多其它邮件服务器列入了黑名单
3，收件人并非我们认识的人
结论，这个邮件服务器很可能被入侵，且被当作垃圾邮件的中继者。
那么，谁会是这个入侵者呢？倒底是什么漏洞导致的？
下面来让找到事件的源头。
首先，根据上面的分析，我们知道发件人和收件人都不是邮件服务器所在域的成员。那么我们就得考虑我们的邮件服务器是不是一个开放的中继(open relay)。
验证：
[root@mail ~]# telnet mail.example.com 25
Trying 124.172.224.76...
Connected to mail.example.com (124.172.224.76).
Escape character is '^]'.
220 mail.example.com ESMTP Postfix
helo aa@bb.com
250 mail.example.com
mail from:aa@bb.com
250 2.1.0 Ok
rcpt to:445335413@qq.com
554 5.7.1 <445335413@qq.com>: Relay access denied
可以看到，我们不经过认证发送邮件给qq邮箱并没有成功。所以，这并不是一个open relay的服务器！既然如此，那别人想用我的邮件服务器外发邮件，那么就必需要通过认证才可以。那么让我们用认证的方式登录并偿试伪造发信人地址外发邮件！
先将用户名和密码经过base64编码。
[root@mail ~]# perl -MMIME::Base64 -e "print encode_base64('123456');"
MTIzNDU2
[root@mail ~]# perl -MMIME::Base64 -e "print encode_base64('test1@example.com');"
dGVzdDFAZXhhbXBsZS5jb20=
验证：
[root@mail ~]# telnet mail.example.com 25
Trying 124.172.224.76...
Connected to mail.example.com (124.172.224.76).
Escape character is '^]'.
220 mail.example.com ESMTP Postfix
auth login
334 VXNlcm5hbWU6
dGVzdDFAZXhhbXBsZS5jb20=
334 UGFzc3dvcmQ6
MTIzNDU2
235 2.7.0 Authentication successful
mail from:test@yahoo.com
250 2.1.0 Ok
rcpt to:445335413@qq.com
250 2.1.5 Ok
data
354 End data with <CR><LF>.<CR><LF>
hello inveracious test!
.
250 2.0.0 Ok: queued as 99F4C23F008
quit
221 2.0.0 Bye
Connection closed by foreign host.
上面我用认证用户test1@example.com登录后，伪造成test@yahoo.com来发信。结果显示成功！我们再回到服务器端看看有什么日志产生！
localhost# tail /var/log/maillog
Oct 26 02:54:27 localhost postfix/qmgr[40723]: 99F4C23F008: from=<test@yahoo.com>, size=197, nrcpt=1 (queue active)
Oct 26 02:54:27 localhost postfix/smtp[41094]: 99F4C23F008: to=<445335413@qq.com>, relay=mx3.qq.com[119.147.192.199]:25, delay=110, delays=109/0/0.04/0.1, dsn=5.0.0, status=bounced (host mx3.qq.com[119.147.192.199] said: 550 Mail content denied. http://service.mail.qq.com/cgi-bin/help?subtype=1&&id=20022&&no=1000726 (in reply to end of DATA command))
Oct 26 02:54:27 localhost postfix/cleanup[41089]: 69EA423F027: message-id=<20121025185427.69EA423F027@mail.example.com>
Oct 26 02:54:27 localhost postfix/bounce[41095]: 99F4C23F008: sender non-delivery notification: 69EA423F027
Oct 26 02:54:27 localhost postfix/qmgr[40723]: 69EA423F027: from=<>, size=2203, nrcpt=1 (queue active)
Oct 26 02:54:27 localhost postfix/qmgr[40723]: 99F4C23F008: removed
日志显示邮件ID为99F4C23F008的邮件，发件人是test@yahoo.com。接收服务器是mx3.qq.com的25端口。状态是被退回。通过http://service.mail.qq.com/cgi-bin/help?subtype=1&&id=20022&&no=1000726 可以查看到拒绝原因。
经过认证登录后的用户，可以伪造发件人随意外发邮件！
由以上信息我们可以推断，很可能是由于别人盗用了我们的账号，然后利用我们的账号伪造其它发信人，疯狂外发邮件！那么，我们现在需要从三方面着手。
1，找出真正的发件人是哪个合法用户并马上修改密码。
2，阻止邮件继续疯狂外发。
3，禁止认证用户伪造发件人外发邮件。
解决
1，找出可能被盗号的用户！
通过maillog虽然看不到被拒绝邮件到底是谁发出的，但可以看到被拒绝投递的邮件ID.就比如下面两封邮件的ID分别为45C4E130CB 4728312BBA。这时候，我们可以查找到一些收信地址比较可疑的邮件来分析。
localhost# tail /var/log/maillog
Oct 22 16:41:38 localhost postfix/error[18801]: 45C4E130CB: to=<blantonlarry@bellsouth.net>, relay=none, delay=101364, delays=95002/6357/0/5.3, dsn=4.0.0, status=deferred (delivery temporarily suspended: host gateway-f1.isp.att.net[204.127.217.16] refused to talk to me: 550-124.172.224.76 blocked by ldap:ou=rblmx,dc=att,dc=net 550 Error - Blocked for abuse. See http://att.net/blocks)
Oct 22 16:41:38 localhost postfix/error[18103]: 4728312BBA: to=<bhaitov@yahoo.com>, relay=none, delay=102971, delays=96576/6386/0/9.8, dsn=4.7.1, status=deferred (delivery temporarily suspended: host mta5.am0.yahoodns.net[66.94.237.139] refused to talk to me: 421 4.7.1 [TS03] All messages from 124.172.224.76 will be permanently deferred; Retrying will NOT succeed. See http://postmaster.yahoo.com/421-ts03.html)
.....
我们可以通过postcat -q命令来查看指定ID邮件的详细内容。比如我觉得ID为2FDF423FA50的邮件很可疑，那么让我们详细看看邮件：
localhost# postcat -q 2FDF423FA50
*** ENVELOPE RECORDS deferred/2/2FDF423FA50 ***
message_size: 2428 4714 50 0 2428
message_arrival_time: Wed Oct 24 06:18:07 2012
create_time: Wed Oct 24 06:18:08 2012
named_attribute: log_ident=2FDF423FA50
named_attribute: rewrite_context=remote
named_attribute: sasl_method=LOGIN <-----sasl认证通过
named_attribute: sasl_username=info@example.com <-------认证用户名
sender: lindawatts101@yahoo.com.hk <-----伪造的发信者
named_attribute: log_client_name=unknown
named_attribute: log_client_address=68.167.29.196 <----登录客户端的ip
named_attribute: log_client_port=1464
named_attribute: log_message_origin=unknown[68.167.29.196]
named_attribute: log_helo_name=User
named_attribute: log_protocol_name=ESMTP
named_attribute: client_name=unknown
named_attribute: reverse_client_name=h-68-167-29-196.mclnva23.static.covad.net
named_attribute: client_address=68.167.29.196
named_attribute: client_port=1464
named_attribute: helo_name=User
named_attribute: protocol_name=ESMTP
named_attribute: client_address_type=2
named_attribute: dsn_orig_rcpt=rfc822;ajagoodin@yahoo.com
original_recipient: ajagoodin@yahoo.com
recipient: ajagoodin@yahoo.com <------收件人1
named_attribute: dsn_orig_rcpt=rfc822;ajagostinelli@cox.net
original_recipient: ajagostinelli@cox.net <------收件人2
recipient: ajagostinelli@cox.net
named_attribute: dsn_orig_rcpt=rfc822;ajagra2001@yahoo.com
original_recipient: ajagra2001@yahoo.com <------收件人3
recipient: ajagra2001@yahoo.com
.........
通过上面的这封邮件，我们可以知道，这封邮件是由info@example.com.这个用户来认证登录的。登录者IP 68.167.29.196。该用户将发信人伪造成：lindawatts101@yahoo.com.hk。并且同时发送很多封邮件出去！ 如果真存在lindawatts101@yahoo.com.hk这个用户的话，那这个用户信箱估计也被塞满了无数退信邮件.
很显然，上面这封邮件并不是一封正常邮件！通过这封邮件很快就可以确定这个用户的密码很可能是被别人破解了！或者邮件系统有其它漏洞，入侵者亲自建立了该用户用来群发邮件。
搜索/var/spool/postfix/defrred目录下面的ip 68.167.29.196,发现有5600邮件被阻塞着。而且还在不断增加。且用户均为info@example.com。可以确定，IP 68.167.29.196为入侵者。
localhost# cd /var/spool/postfix/defrred
localhost# find . -exec grep "68.167.29.196" {} \; | wc -l
5625
登录数据库查看info@example.com这个用户的创建情况。这个在webman管理后台上面是看不到的。
localhost# /usr/opt/local/mysql-5.1.47/bin/mysql -uextmail -pextmail
mysql> select * from mailbox where username='info@example.com'\G;
*************************** 1. row ***************************
username: info@example.com
uid: info
password: $1$RpyMEokE$CK31uufL9uNk6PjqSorXa1
clearpwd:
name:
mailhost:
maildir: example.com/info/Maildir/
homedir: example.com/info
quota: 524288000S
netdiskquota: 524288000S
domain: example.com
uidnumber: 1000
gidnumber: 1000
createdate: 2012-04-25 15:35:54 <-----创建日期
expiredate: 0000-00-00
active: 1
disablepwdchange: 0
disablesmtpd: 0
disablesmtp: 0
disablewebmail: 0
disablenetdisk: 0
disableimap: 1
disablepop3: 0
question:
answer:
1 row in set (0.00 sec)
mysql> select * from manager;
+------------------+------------------------------------+-------+------+------------+-------------+-----------+------------------+---------------------+------------+--------+
| username | password | type | uid | name | question | answer | disablepwdchange | createdate | expiredate | active |
+------------------+------------------------------------+-------+------+------------+-------------+-----------+------------------+---------------------+------------+--------+
| root@extmail.org | $1$ZwYBBBz1$mh.Uwro5vqXMwYum0eprq/ | admin | root | Super User | my question | my answer | 0 | 2007-02-14 15:10:04 | 2010-11-08 | 1 |
+------------------+------------------------------------+-------+------+------------+-------------+-----------+------------------+---------------------+------------+--------+
管理员账号只有一个，info@example.com也不是新建的。那应该是Info@example.com的用户密码被破解了。
来看看info@example.com这个用户的登录日志。发现全是由68.167.29.196的主机登录的。
localhost# cat /var/log/maillog | grep info@example.com
Oct 24 00:32:10 localhost postfix/smtpd[4202]: 8F005249014: client=unknown[68.167.29.196], sasl_method=LOGIN, sasl_username=info@example.com
Oct 24 00:32:16 localhost postfix/smtpd[5029]: 11044249024: client=unknown[68.167.29.196], sasl_method=LOGIN, sasl_username=info@example.com
Oct 24 00:32:17 localhost postfix/smtpd[4626]: 930FB249028: client=unknown[68.167.29.196], sasl_method=LOGIN, sasl_username=info@example.com
Oct 24 00:32:17 localhost postfix/smtpd[4765]: A890624902B: client=unknown[68.167.29.196], sasl_method=LOGIN, sasl_username=info@example.com
登录extman，将info@example.com这个用户的密码改掉。
我们登录info@example.com来看看用户情况。结果发现有一万多封退信信息，由于这个账号没人用，所以一直未发现这个问题。
2，清除所有缓存垃圾邮件，阻止邮件服务器继续偿试外发！
清除defer和deferred目录下的缓存邮件
我们来瞧瞧邮件缓存目录
localhost# du -sh /var/spool/postfix/*
2.1G /var/spool/postfix/defer
2.7G /var/spool/postfix/deferred
可以看到，被延迟发送的邮件占用了5个g的空间！
清除邮件中的所有队列
localhost# postsuper -d ALL
postsuper: Deleted: 292551 messages
共清除了将近30万封缓存的邮件。
如果缓存邮件里面有重要邮件，不能删除所有邮件，那么也可以写一个脚本，只清除所有属于68.167.29.196的缓存邮件。
localhost# vi deldefer.sh
#删除defferred中的缓存
cd /var/spool/postfix/deferred/
find . -exec grep 68.167.29.196 {} \; | awk '{print $3}' | cut -d/ -f3 >/tmp/del.txt
for i in `cat /tmp/del.txt`
do
postsuper -d "$i"
done
rm -rf /tmp/del.txt
#删除deffer中的缓存
cd /var/spool/postfix/defer
for i in `find .|cut -d/ -f3`
do
postcat -q $i |grep 68.167.29.196
if [ $? -eq 0 ];
then
echo $i >> /tmp/defer.txt
postsuper -d $i
fi
done
rm -rf /tmp/defer.txt
脚本说明：
在删除deffer和defferred下面的缓存邮件的脚本是不同的。由于defer下的缓存邮件用cat直接查看是看不到发件人及登录ip等详细信息的，需要用postcat来查看才能显示出详细的信息。所以deffer目录里的清除脚本写法和上面defferred的有些不同。注意：在删除了deferred下面的缓存后，如果不删除defer的缓存，defer下的邮件仍然会被不停的投递出去，直到最后变为deferred之后才会放弃。所以，如果只删除deferred下面的邮件而不删除defer下面的邮件的话，过不了多久，deferred下面又会出现大量邮件，而这个邮件是由defer目录下的缓存引起的。
-------------------------------------------------------
再次查看缓存目录，容量终于恢复正常值。
localhost# du -sh /var/spool/postfix/*
162K /var/spool/postfix/defer
46K /var/spool/postfix/deferred
删除info@example.com用户邮箱的退信邮件
下面该删除info@example.com用户的所有退信邮件了.通过查看邮件发现所有的垃圾邮件均是今天一天生成的。到服务器端查找并删除今天的所有邮件。
进入到info用户的邮件目录
localhost# cd /usr/opt/home/domains/example.com/info/Maildir/
可以看到有12779封邮件。
localhost# ls -l cur/ |wc -l
12779
查找今天生成的邮件，共11589封
localhost# find cur/ -ctime -1 | wc -l
11589
删除所有今天的邮件
localhost# find cur/ -ctime -1 -exec rm -f {} \;
删除完毕！
注意find cur/ -ctime -1 -exec rm -f {} \; 中是rm -f ！不要写成了rm -rf。否则一执行就把cur目录给删掉了。那么用户以前的邮件也全带着一起删除了！
至此，邮件服务器终于恢复了正常运行。再次用tail -f 来查看日志，不会再出现那恐怖的疯狂刷屏日志了!疯狂的服务器终于恢复了原来的悠闲状态！
3，禁止认证用户假冒发信人外发
修改main.cf配置文件，增加发信人限制功能！
localhost# vi main.cf
mynetworks = 127.0.0.0/8
smtpd_sender_restrictions =
permit_mynetworks,
reject_sender_login_mismatch,
reject_non_fqdn_sender,
reject_authenticated_sender_login_mismatch,
reject_unauthenticated_sender_login_mismatch,
reject_non_fqdn_recipient,
reject_invalid_hostname,
reject_unknown_sender_domain,
check_sender_access hash:/etc/postfix/sender_access
smtpd_sender_login_maps =
mysql:/etc/postfix/mysql_virtual_sender_maps.cf,
mysql:/etc/postfix/mysql_virtual_alias_maps.cf
localhost# postfix reload
在客户端测试效果：
客户端伪造发信人测试，test1@example.com伪造成发件人test@yahoo.com未成功！
[root@mail ~]# perl -MMIME::Base64 -e "print encode_base64('123456');"
MTIzNDU2
[root@mail ~]# perl -MMIME::Base64 -e "print encode_base64('test1@example.com');"
dGVzdDFAZXhhbXBsZS5jb20=
[root@mail ~]# telnet mail.example.com 25
Trying 124.172.224.76...
Connected to mail.example.com (124.172.224.76).
Escape character is '^]'.
auth login
220 mail.example.com ESMTP Postfix
334 VXNlcm5hbWU6
dGVzdDFAZXhhbXBsZS5jb20=
334 UGFzc3dvcmQ6
MTIzNDU2
235 2.7.0 Authentication successful
mail from:test@yahoo.com
250 2.1.0 Ok
rcpt to:445335413@qq.com
553 5.7.1 <test@yahoo.com>: Sender address rejected: not owned by user test1@example.com
客户端用真实的地址发信测试成功
[root@mail ~]# telnet mail.example.com 25
Trying 124.172.224.76...
auConnected to mail.example.com (124.172.224.76).
Escape character is '^]'. 220 mail.example.com ESMTP Postfix
auth login
334 VXNlcm5hbWU6
dGVzdDFAZXhhbXBsZS5jb20=
334 UGFzc3dvcmQ6
MTIzNDU2
235 2.7.0 Authentication successful
mail from:test1@example.com
250 2.1.0 Ok
rcpt to:445335413@qq.com
250 2.1.5 Ok
Ok，测试成功！
关于邮件服务器被yahoo,gmail,hotmail等邮件服务器列入黑名单问题，这个最好是换个ip地址吧。一个个申诉太麻烦了！
