Topic: qmail queue build up and mail halt

[JasonS]

*Resolution in comment 13*




*Resolution in comment 13*
Hello all, I hope I'm posting this in the correct location. I've done extensive searching, but I think I need a little more hand-holding to fix my problem.

Please treat me as a linux/sme noob, and only a novice when it comes to email troubleshooting. I've inherited an SME server to administer and am trying to come up to speed.

What we've got:

sme 7.6, updates done. ClamAV 0.97.7

Our sme server is the front end smtp server for our exchange server. In the past few days our email has been trickling in and I see that there are 45343 messages in the qmHandle -s report. Mail is effectively halted.
I've also got an email from our ISP suggesting we are spamming.

The example they gave shows TO: random@aol.com
return-path: <anonymous@jasonsdomain.com>
reply-to ptbz@jasonsdomain.com   -an account that doesn't actually exist. (obviously i'm changing my domain name to jasonsdomain.com for security purposes in this post)
message-id: 20130417195391.29850.qmail@jasonsdomain.com
X-AOL-Ip: myexternalMailip/MX record ip



pertinent config information:
[root@mail control]# config show qpsmtpd
qpsmtpd=service
    Bcc=disabled
    BccMode=cc
    BccUser=maillog
    DNSBL=enabled
    LogLevel=6
    MaxScannerSize=25000000
    RBLList=zen.spamhaus.org:whois.rfc-ignorant.org:dnsbl.njabl.org
    RHSBL=enabled
    RequireResolvableFromHost=yes
    SBLList=dsn.rfc-ignorant.org
    TlsBeforeAuth=1
    access=public
    qplogsumm=disabled
    status=enabled


E-mail settings
POP3 server access    Allow access only from local networks
IMAP server access    Allow access only from local networks
Webmail access    Allow HTTPS (secure)

Virus scanning    Enabled
Spam filtering    Enabled
Executable content blocking    Disabled

E-mail retrieval mode    Standard (SMTP)
SMTP authentication    Allow SSMTP (secure)

E-mail to unknown users    Reject
Address of internal mail server    10.1.0.12  (our exchange server)
Address of Internet provider's mail server    



a small snippet of tail -f /var/log/qmail/current

_messages_from_<MY IP ADDRESS>_will_be_permanently_deferred;_Retrying_will_NOT_succeed._See_http://postmaster.yahoo.com/421-ts03.html/
@40000000517017a9398ed33c status: local 0/10 remote 19/20
@40000000517017a939eef0b4 starting delivery 18614: msg 2754207 to remote addressReplaced@aol.com
@40000000517017a939eef884 status: local 0/10 remote 20/20
@40000000517017aa1093956c delivery 18614: deferral: Connected_to_205.188.103.2_but_greeting_failed./Remote_host_said:_421_mtain-

dd05.r1000.mx.aol.com_Service_unavailable_-_try_again_later/
@40000000517017aa1093956c status: local 0/10 remote 19/20
@40000000517017aa11f5ec5c starting delivery 18615: msg 1701293 to remote differentAddressReplaced@aol.com
@40000000517017aa11f5f814 status: local 0/10 remote 20/20
@40000000517017aa2dbb448c delivery 18612: deferral: Connected_to_212.27.48.7_but_greeting_failed./Remote_host_said:_421_Too_many_spams_from_your_IP_

(64.4.92.13),_please_visit_http://postmaster.free.fr//


/var/qmail/bin/qmail-qread shows pretty much exclusively entries like this:

18 Apr 2013 05:57:09 GMT  #2758298  414  <anonymous@jasonsdomain.com>
        remote  eju****@aol.com
18 Apr 2013 13:46:55 GMT  #2037363  390  <anonymous@jasonsdomain.com>
        remote  ju***@comcast.net
18 Apr 2013 07:33:43 GMT  #2760092  429  <anonymous@jasonsdomain.com>
        remote  matth*****7@yahoo.com


I have stopped qmail and qpsmtpd via
sv d /service/qpsmtpd
sv d /service/qmail


I don't really know what else to show you guys or how to proceed..direction would be so very welcome! We're doing scans on our local machines (150'ish), but if there is a way to pinpoint trouble from sme that would be awesome.

Thanks for any and all assistance!
Jason

[JasonS]

I created anonymous@jasonsdomain.com on our exchange server just to see what was in the anonymous emails:

There are a bunch of these:
fyi: ehmj@jasonsdomain.com are both fake/nonexistant addresses in our domain.


-----Original Message-----
From: MAILER-DAEMON@jasonsdomain.com [mailto:MAILER-DAEMON@jasonsdomain.com]
Sent: Thu 4/18/2013 8:13 AM
To: Anonymous Anonymous
Subject: failure notice
 
Hi. This is the qmail-send program at jasonsdomain.com.
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.

<mike-1004@hotmail.com>:
65.55.37.88 does not like recipient.
Remote host said: 550 Requested action not taken: mailbox unavailable Giving up on 65.55.37.88.

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

Return-Path: <anonymous@jasonsdomain.com>
Received: (qmail 10932 invoked by uid 102); 18 Apr 2013 12:28:49 -0000
Date: 18 Apr 2013 12:28:49 -0000
Message-ID: <20130418122849.10931.qmail@jasonsdomain.com>
To: mike-***@hotmail.com
Subject: A pilll can make all thee difference innn thhhe bdroooom
From: ehmj@jasonsdomain.com
Reply-To: ehmj@jasonsdomain.com

AAA singlee pll rraiises the  immuunitty aaa  dozen ttimes!

http:// slacker.cl /back/ administrator/ m6jq6c.php   (random link. different in each email).
----end message------

[holck]

I am not too experienced myself, but I will suggest that you take a look in /var/log/qpsmtpd/current and /var/log/sqpsmtpd/current . These files will tell you which IP adresses are trying to send mail through your server. My guess is that you have an infected PC on your network, and by looking through the log files, you can find the IP address of the infected machine. Then in /var/log/messages for relevant DHCP messages, you can find some information regarding the PC with this IP address.

Good luck,
Jesper

[JasonS]

thanks for the message, Jesper

I poked through /var/log/qpsmtpd/current -
I'm not entirely sure what I'm looking for, but I don't see any local addresses (which would be 10.1.x.x) listed in the file.
I do see 192.168.1.101 and .102 associated with what look to be legitimate emails. Is this normal?

our sme server is 10.1.0.13 and our exchange server is 10.1.0.12  --
not sure why I would be seeing 192.168.1.101/102...

2013-04-18 08:57:26.562327500 27253 Accepted connection 1/40 from 64.59.136.138 / smtp-out-02.shaw.ca
2013-04-18 08:57:26.562512500 27253 Connection from smtp-out-02.shaw.ca [64.59.136.138]
2013-04-18 08:57:26.565010500 27253 tls plugin (init): ciphers: HIGH:!SSLv2
2013-04-18 08:57:27.574875500 27253 check_earlytalker plugin (connect): remote host said nothing spontaneous, proceeding
2013-04-18 08:57:27.580605500 27253 220 mail.mydomain.com ESMTP
2013-04-18 08:57:27.604865500 27253 dispatching EHLO smtp-out-02.shaw.ca
2013-04-18 08:57:27.605873500 27253 250-mydomain.com Hi smtp-out-02.shaw.ca [64.59.136.138]
2013-04-18 08:57:27.605875500 27253 250-PIPELINING
2013-04-18 08:57:27.605877500 27253 250-8BITMIME
2013-04-18 08:57:27.605879500 27253 250-SIZE 15000000
2013-04-18 08:57:27.605881500 27253 250 STARTTLS
2013-04-18 08:57:27.650872500 27253 dispatching MAIL FROM:<tank@someplaceelse.org> SIZE=4272
2013-04-18 08:57:27.650875500 27253 full from_parameter: FROM:<tank@someplaceelse.org> SIZE=4272
2013-04-18 08:57:27.667755500 27253 getting mail from <tank@someplaceelse.org>
2013-04-18 08:57:27.667758500 27253 250 <tank@someplaceelse.org>, sender OK - how exciting to get mail from you!
2013-04-18 08:57:27.687147500 27253 dispatching RCPT TO:<Neil@mydomain.com>
2013-04-18 08:57:27.697008500 27253 250 <Neil@mydomain.com>, recipient ok
2013-04-18 08:57:27.719402500 27253 dispatching RCPT TO:<carlos@mydomain.com>
2013-04-18 08:57:27.728613500 27253 250 <carlos@mydomain.com>, recipient ok
2013-04-18 08:57:27.793840500 27253 dispatching DATA
2013-04-18 08:57:27.793842500 27253 354 go ahead
2013-04-18 08:57:27.793844500 27253 spooling message to disk
2013-04-18 08:57:32.551378500 27253 spamassassin plugin (data_post): check_spam: No, hits=1.6, required=5.0, tests=HTML_MESSAGE,RCVD_IN_DNSWL_NONE,SUBJ_ALL_CAPS
2013-04-18 08:57:32.551381500 27253 virus::clamav plugin (data_post): Changing permissions on file to permit scanner access
2013-04-18 08:57:32.633146500 27253 virus::clamav plugin (data_post): clamscan results: /var/spool/qpsmtpd/1366293447:27253:0: OK
2013-04-18 08:57:32.633150500 27253 logging::logterse plugin (queue): ` 64.59.136.138   smtp-out-02.shaw.ca   smtp-out-02.shaw.ca   <tank@someplaceelse.org>   <Neil@mydomain.com>,<carlos@mydomain.com>   queued      <p06240803cd95aa6fd978@[192.168.1.102]>   No, hits=1.6 required=5.0_
2013-04-18 08:57:32.653536500 27253 250 Queued! 1366293452 qp 27345 <p06240803cd95aa6fd978@[192.168.1.102]>

[JasonS]

looking at the qmail/current log, i'm seeing a lot of weird stuff. I don't know if I'm reading it right, but it suggests to me that something in sme server (or via one of the hosted webpages?) is initiating these emails. Not too sure, and not really sure how to check/test that theory. Qmail will deliver mail from internet to my internal exchange until it reaches about 40,000 messages in queue at which point it seems to choke and die. If i stop qmail and delete messages in remote queue with qmHandle -h'yahoo.com' or aol.com, this pares it down to 10,000'ish messages, and mail will continue processing. But, afaik, there shouldn't even be messages in remote queue not intended for my local exchange server. Our exchange server sends out to the internet directly, not through SME.

We have a number of webshares setup along with 2 ibays for two websites
I just noticed that anonymous is set as a pseudonym for administrator... does this mean that something is (probably?) sending email out from Administrator?

here's what I'm seeing. addresses on my internal domain will be marked as @mydomain.com

If I pick one message ID from qmail/current, this is the chain:

2013-04-18 21:22:07.107071500 starting delivery 97283: msg 928834 to remote randomemail@aol.com
2013-04-18 21:22:08.001253500 end msg 928834
2013-04-18 21:24:50.270147500 new msg 928834
2013-04-18 21:24:50.270204500 info msg 928834: bytes 1115 from <> qp 29264 uid 406
2013-04-18 21:24:50.276887500 starting delivery 98508: msg 928834 to remote anonymous@mydomain.com
2013-04-18 21:24:50.466759500 end msg 928834
2013-04-18 21:24:53.112697500 new msg 928834
2013-04-18 21:24:53.112699500 info msg 928834: bytes 436 from <anonymous@mydomain.com> qp 29310 uid 102
2013-04-18 21:24:53.122536500 starting delivery 98530: msg 928834 to remote randomemail@yandex.ru
2013-04-18 21:24:54.656698500 end msg 928834
2013-04-18 21:24:54.838456500 new msg 928834
2013-04-18 21:24:54.838512500 info msg 928834: bytes 1102 from <> qp 29330 uid 406
2013-04-18 21:24:54.844122500 starting delivery 98536: msg 928834 to remote anonymous@mydomain.com
2013-04-18 21:24:55.060400500 end msg 928834
**this continues a little longer**

the following is an uninterrupted snippet. The entire qmail/current log looks like this.


2013-04-18 21:25:37.462253500 new msg 928794
2013-04-18 21:25:37.462255500 info msg 928794: bytes 414 from <anonymous@mydomain.com> qp 30067 uid 102
2013-04-18 21:25:37.472183500 starting delivery 98803: msg 928794 to remote dochiatt2003@yahoo.com
2013-04-18 21:25:37.472185500 status: local 0/10 remote 3/20
2013-04-18 21:25:37.647369500 new msg 928836
2013-04-18 21:25:37.647371500 info msg 928836: bytes 406 from <anonymous@mydomain.com> qp 30075 uid 102
2013-04-18 21:25:37.658092500 starting delivery 98804: msg 928836 to remote terryg11@cox.net
2013-04-18 21:25:37.658095500 status: local 0/10 remote 4/20
2013-04-18 21:25:37.665163500 delivery 98801: deferral: Connected_to_205.188.146.194_but_greeting_failed./Remote_host_said:_421_mtain-dh03.r1000.mx.aol.com_Service_unavailable_-_try_again_later/
2013-04-18 21:25:37.665166500 status: local 0/10 remote 3/20
2013-04-18 21:25:37.813950500 delivery 98803: deferral: Connected_to_66.196.118.240_but_greeting_failed./Remote_host_said:_421_4.7.1_[TS03]_All_messages_from_64.4.92.13_will_be_permanently_deferred;_Retrying_will_NOT_succeed._See_http://postmaster.yahoo.com/421-ts03.html/
2013-04-18 21:25:37.813954500 status: local 0/10 remote 2/20
2013-04-18 21:25:39.403983500 delivery 98804: success: 68.6.19.3_accepted_message./Remote_host_said:_250_2.0.0_RfRd1l04e0HHfW801fReLB_mail_accepted_for_delivery/
2013-04-18 21:25:39.403987500 status: local 0/10 remote 1/20
2013-04-18 21:25:39.403989500 starting delivery 98805: msg 2752040 to remote sunblahblah@yahoo.com
2013-04-18 21:25:39.403991500 status: local 0/10 remote 2/20
2013-04-18 21:25:39.403993500 end msg 928836
2013-04-18 21:25:39.404168500 starting delivery 98806: msg 2752039 to remote peidblahblah@yahoo.com
2013-04-18 21:25:39.404171500 status: local 0/10 remote 3/20
2013-04-18 21:25:39.404241500 starting delivery 98807: msg 2747905 to remote jillblahblah4@aol.com
2013-04-18 21:25:39.404243500 status: local 0/10 remote 4/20
2013-04-18 21:25:39.404429500 starting delivery 98808: msg 2749168 to remote danblahblah@btinternet.com
2013-04-18 21:25:39.404431500 status: local 0/10 remote 5/20
2013-04-18 21:25:39.406090500 starting delivery 98809: msg 929062 to remote gblahblahr@yahoo.com
2013-04-18 21:25:39.406093500 status: local 0/10 remote 6/20
2013-04-18 21:25:39.407459500 starting delivery 98810: msg 2749171 to remote dblahblah@yahoo.com
2013-04-18 21:25:39.407461500 status: local 0/10 remote 7/20
2013-04-18 21:25:39.408827500 starting delivery 98811: msg 2000955 to remote rblah@aol.com
2013-04-18 21:25:39.408829500 status: local 0/10 remote 8/20
2013-04-18 21:25:39.410168500 starting delivery 98812: msg 2747907 to remote nasblah@aol.com
2013-04-18 21:25:39.410170500 status: local 0/10 remote 9/20
2013-04-18 21:25:39.411540500 starting delivery 98813: msg 2751060 to remote blagl@aol.com
2013-04-18 21:25:39.411543500 status: local 0/10 remote 10/20
2013-04-18 21:25:39.412604500 starting delivery 98814: msg 2749170 to remote ablah@aol.com
2013-04-18 21:25:39.412606500 status: local 0/10 remote 11/20
2013-04-18 21:25:39.414235500 starting delivery 98815: msg 2751059 to remote tblah9@verizon.net
2013-04-18 21:25:39.414238500 status: local 0/10 remote 12/20
2013-04-18 21:25:39.415591500 starting delivery 98816: msg 2752041 to remote mblah@aol.com
2013-04-18 21:25:39.415593500 status: local 0/10 remote 13/20
2013-04-18 21:25:39.520388500 delivery 98810: deferral: Connected_to_98.138.112.37_but_greeting_failed./Remote_host_said:_421_4.7.1_[TS03]_All_messages_from_64.4.92.13_will_be_permanently_deferred;_Retrying_will_NOT_succeed._See_http://postmaster.yahoo.com/421-ts03.html/
2013-04-18 21:25:39.520392500 status: local 0/10 remote 12/20
2013-04-18 21:25:39.563397500 delivery 98815: deferral: Connected_to_206.46.232.11_but_greeting_failed./Remote_host_said:_571_Email_from_64.4.92.13_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._130418/
2013-04-18 21:25:39.563402500 status: local 0/10 remote 11/20
2013-04-18 21:25:39.700875500 delivery 98806: deferral: Connected_to_98.138.112.37_but_greeting_failed./Remote_host_said:_421_4.7.1_[TS03]_All_messages_from_64.4.92.13_will_be_permanently_deferred;_Retrying_will_NOT_succeed._See_http://postmaster.yahoo.com/421-ts03.html/
2013-04-18 21:25:39.700879500 status: local 0/10 remote 10/20
2013-04-18 21:25:39.701816500 delivery 98805: deferral: Connected_to_98.138.112.35_but_greeting_failed./Remote_host_said:_421_4.7.1_[TS03]_All_messages_from_64.4.92.13_will_be_permanently_deferred;_Retrying_will_NOT_succeed._See_http://postmaster.yahoo.com/421-ts03.html/
2013-04-18 21:25:39.701819500 status: local 0/10 remote 9/20
2013-04-18 21:25:39.704325500 delivery 98813: deferral: Connected_to_205.188.190.1_but_greeting_failed./Remote_host_said:_421_mtain-de01.r1000.mx.aol.com_Service_unavailable_-_try_again_later/
2013-04-18 21:25:39.704329500 status: local 0/10 remote 8/20
2013-04-18 21:25:39.704415500 delivery 98809: deferral: Connected_to_98.138.112.37_but_greeting_failed./Remote_host_said:_421_4.7.1_[TS03]_All_messages_from_64.4.92.13_will_be_permanently_deferred;_Retrying_will_NOT_succeed._See_http://postmaster.yahoo.com/421-ts03.html/
2013-04-18 21:25:39.704418500 status: local 0/10 remote 7/20
2013-04-18 21:25:39.728002500 delivery 98807: deferral: Connected_to_205.188.190.1_but_greeting_failed./Remote_host_said:_421_mtain-de01.r1000.mx.aol.com_Service_unavailable_-_try_again_later/
2013-04-18 21:25:39.728006500 status: local 0/10 remote 6/20
2013-04-18 21:25:39.804488500 delivery 98808: deferral: Connected_to_188.125.69.78_but_greeting_failed./Remote_host_said:_421_4.7.1_[TS03]_All_messages_from_64.4.92.13_will_be_permanently_deferred;_Retrying_will_NOT_succeed._See_http://postmaster.yahoo.com/421-ts03.html/
2013-04-18 21:25:39.804492500 status: local 0/10 remote 5/20
2013-04-18 21:25:39.883707500 delivery 98811: deferral: Connected_to_205.188.146.194_but_greeting_failed./Remote_host_said:_421_mtain-dh04.r1000.mx.aol.com_Service_unavailable_-_try_again_later/
2013-04-18 21:25:39.883711500 status: local 0/10 remote 4/20
2013-04-18 21:25:39.948710500 delivery 98816: deferral: Connected_to_64.12.90.33_but_greeting_failed./Remote_host_said:_421_mtain-mg03.r1000.mx.aol.com_Service_unavailable_-_try_again_later/
2013-04-18 21:25:39.948714500 status: local 0/10 remote 3/20
2013-04-18 21:25:39.983172500 delivery 98814: deferral: Connected_to_64.12.90.33_but_greeting_failed./Remote_host_said:_421_mtain-mg03.r1000.mx.aol.com_Service_unavailable_-_try_again_later/
2013-04-18 21:25:39.983177500 status: local 0/10 remote 2/20
2013-04-18 21:25:40.029303500 delivery 98812: deferral: Connected_to_64.12.90.33_but_greeting_failed./Remote_host_said:_421_mtain-mg03.r1000.mx.aol.com_Service_unavailable_-_try_again_later/
2013-04-18 21:25:40.029306500 status: local 0/10 remote 1/20



spamd/current: seems to be showing errors. pyzor terminated, signal 15, as well as RR at octet 37 corrupt/incomplete at /usr/lib/perl5/vendor_perl/5.8.5/Mail/SpamAssassin/DnsResolver.pm line 457.
I'll research these errors...

2013-04-18 09:50:39.823205500 Apr 18 09:50:39.823 [3977] info: prefork: child states: II
2013-04-18 09:51:11.870738500 Apr 18 09:51:11.869 [4751] info: spamd: connection from localhost [127.0.0.1] at port 39580
2013-04-18 09:51:11.875515500 Apr 18 09:51:11.873 [4751] info: spamd: checking message <20130418012940.13060.94736@smtpbackup.bhreeves.com> for qpsmtpd:1005
2013-04-18 09:51:17.285742500 Apr 18 09:51:17.284 [4751] info: pyzor: [13129] error: TERMINATED, signal 15 (000f)
2013-04-18 09:51:17.294291500 Apr 18 09:51:17.294 [4751] info: spamd: clean message (2.4/5.0) for qpsmtpd:1005 in 5.4 seconds, 6275 bytes.
2013-04-18 09:51:17.294608500 Apr 18 09:51:17.295 [4751] info: spamd: result: . 2 - HTML_MESSAGE,MIME_HTML_ONLY,RDNS_NONE,T_REMOTE_IMAGE scantime=5.4,size=6275,user=qpsmtpd,uid=1005,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=39580,mid=<20130418012940.13060.94736@smtpbackup.bhreeves.com>,autolearn=disabled
2013-04-18 09:51:17.385720500 Apr 18 09:51:17.385 [3977] info: prefork: child states: II
2013-04-18 09:51:18.360840500 Apr 18 09:51:18.359 [4751] info: spamd: connection from localhost [127.0.0.1] at port 39623
2013-04-18 09:51:18.365585500 Apr 18 09:51:18.363 [4751] info: spamd: checking message <20130418012940.13060.88792@smtpbackup.bhreeves.com> for qpsmtpd:1005
2013-04-18 09:51:23.415863500 Apr 18 09:51:23.412 [4752] info: spamd: connection from localhost [127.0.0.1] at port 39654
2013-04-18 09:51:23.419858500 Apr 18 09:51:23.420 [4752] info: spamd: checking message <300.0.47.235.1CE3C4383418E3A.47E8F@me-ss2-bk3zur.mailengine1.com> for qpsmtpd:1005
2013-04-18 09:51:23.774344500 Apr 18 09:51:23.774 [4751] info: pyzor: [13194] error: TERMINATED, signal 15 (000f)
2013-04-18 09:51:23.788016500 Apr 18 09:51:23.788 [4751] info: spamd: clean message (2.4/5.0) for qpsmtpd:1005 in 5.4 seconds, 6351 bytes.
2013-04-18 09:51:23.788351500 Apr 18 09:51:23.788 [4751] info: spamd: result: . 2 - HTML_MESSAGE,MIME_HTML_ONLY,RDNS_NONE,T_REMOTE_IMAGE scantime=5.4,size=6351,user=qpsmtpd,uid=1005,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=39623,mid=<20130418012940.13060.88792@smtpbackup.bhreeves.com>,autolearn=disabled
2013-04-18 09:51:23.886180500 Apr 18 09:51:23.886 [3977] info: prefork: child states: IB
2013-04-18 09:51:30.487851500 Apr 18 09:51:30.486 [4752] info: pyzor: [13253] error: TERMINATED, signal 15 (000f)
2013-04-18 09:51:30.501004500 Apr 18 09:51:30.501 [4752] info: spamd: clean message (1.8/5.0) for qpsmtpd:1005 in 7.1 seconds, 13118 bytes.
2013-04-18 09:51:30.501305500 Apr 18 09:51:30.501 [4752] info: spamd: result: . 1 - HTML_MESSAGE,MIME_HTML_MOSTLY,MPART_ALT_DIFF,RP_MATCHES_RCVD,URIBL_BLACK scantime=7.1,size=13118,user=qpsmtpd,uid=1005,required_score=5.0,rhost=localhost,raddr=127.0.0.1,rport=39654,mid=<300.0.47.235.1CE3C4383418E3A.47E8F@me-ss2-bk3zur.mailengine1.com>,autolearn=disabled
2013-04-18 09:51:30.600363500 Apr 18 09:51:30.600 [3977] info: prefork: child states: II
2013-04-18 09:51:36.637239500 Apr 18 09:51:36.636 [4751] info: spamd: connection from localhost [127.0.0.1] at port 39722
2013-04-18 09:51:36.664977500 Apr 18 09:51:36.661 [4751] info: spamd: checking message <0.0.AC.9E9.1CE3C44D42ED194.0@mta8522.pur3.net> for qpsmtpd:1005
2013-04-18 09:51:38.258125500 Apr 18 09:51:38.248 [4751] warn: Exception: incomplete data at /usr/lib/perl5/vendor_perl/5.8.5/i386-linux-thread-multi/Net/DNS/RR.pm line 608, <GEN459> line 692.
2013-04-18 09:51:38.258131500 Apr 18 09:51:38.248 [4751] warn:  RR at octet 37 corrupt/incomplete at /usr/lib/perl5/vendor_perl/5.8.5/Mail/SpamAssassin/DnsResolver.pm line 457
2013-04-18 09:51:41.007142500 Apr 18 09:51:41.007 [4752] info: spamd: connection from localhost [127.0.0.1] at port 39745

[holck]

What I see from your log files is that your Internet provider has blacklisted your server, so it is not allowed to send mails to the outside world:

Connected_to_206.46.232.11_but_greeting_failed./Remote_host_said:_571_Email_from_64.4.92.13_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._130418/

So you have to go to http://www.verizon.net/whitelist and follow the instructions there.

But first, of course, you need to make sure that none of your clients are infected. Scan through /var/log/qpsmtpd/current and /var/log/sqpsmtpd/current and look for lines like the following:

<carlos@mydomain.com>   queued      <p06240803cd95aa6fd978@[192.168.1.102]>   No, hits=1.6 required=5.0_
2013-04-18 08:57:32.653536500 27253 250 Queued! 1366293452 qp 27345

Here you can see the IP address (192.168.1.102) of a client, trying to send an email. This example seems to be ok, but my guess will be that another client is sending hundreds of mails, quickly following each other. In the example, carlos@mydomain.com is the "from" address used for the email. For the spam messages, the "from" address will probably be something more obscure, not having anything to do with your own domain.

[JasonS]

But first, of course, you need to make sure that none of your clients are infected. Scan through /var/log/qpsmtpd/current and /var/log/sqpsmtpd/current and look for lines like the following:

<carlos@mydomain.com>   queued      <p06240803cd95aa6fd978@[192.168.1.102]>   No, hits=1.6 required=5.0_
2013-04-18 08:57:32.653536500 27253 250 Queued! 1366293452 qp 27345

Here you can see the IP address (192.168.1.102) of a client, trying to send an email. This example seems to be ok, but my guess will be that another client is sending hundreds of mails, quickly following each other. In the example, carlos@mydomain.com is the "from" address used for the email. For the spam messages, the "from" address will probably be something more obscure, not having anything to do with your own domain.

that's an interesting example, Jesper, because the carlos address is a real address. However, we don't send our email out through SME..it goes from exchange straight out to the internet--would/should I even see mail from carlos going outbound from SME?
Also, we don't use a typically use a 192.168.1.102 unless someone is on vpn. I will have to search (again) to see if I spot any lan IP addresses in the 10.1.x.x range. It could be that he was on VPN though...i'll investigate this some more.

[JasonS]

another angle:

I found a post by Charlie Brady here: http://forums.contribs.org/index.php/topic,40965.html , as well as this webpage: http://blog.xfloyd.net/?p=109 that gave some tips on finding out what is causing the spam..

He says:

The first thing you do is to stop qmail. Do it now. Don't delay.

The next is to examine the full mail headers of one or more of the messages. The earliest (i.e. lowest in the message) Received: header will show which computer the message came from. If it came from the SME server itself, "invoked by uid" will show the uid of the process which created the message. 'grep nnn /etc/passwd' will show you the name of that uid.

If the name of the uid is 'www', then something running inside your web server is creating the message. You will need to use your knowledge of what is on your website, and the httpd access_log to determine where the problem is.

[root@mail ~]# /var/qmail/bin/qmail-qread
18 Apr 2013 23:47:59 GMT  #929384  412  <anonymous@mydomain.com>
        remote  kapla@comcast.net

[root@mail ~]# find /var/qmail/queue/mess/ -name 929384
/var/qmail/queue/mess/0/929384

[root@mail ~]# more /var/qmail/queue/mess/0/929384
Received: (qmail 24515 invoked by uid 102); 18 Apr 2013 23:47:59 -0000
Date: 18 Apr 2013 23:47:59 -0000
Message-ID: <20130418234759.24514.qmail@mydomain.com>
To: kapla@comcast.net
Subject: a bunch of spam garbage
From: lqtb@mydomain.com
Reply-To: lqtb@mydomain.com

Choosse  bbbestt VViaggra Pharmmcy online


[root@mail ~]# grep 102 /etc/passwd
www:x:102:102:e-smith web server:/home/e-smith:/bin/false


....sooo... e-smith web server is spamming the world? is that the correct interpretation?
and if so, I have no idea what to do with that information

[Stefano]

no, you have a web application that has been hacked.

stop httpd server

Code: [Select]

service httpd-e-smith stop

then delete and reinstall your web application
please be aware that common php apps (joomla, wordpress and so on) are bugged and must be kept up-to-date
HTH

[JasonS]

no, you have a web application that has been hacked.

stop httpd server

Code: [Select]

service httpd-e-smith stop

then delete and reinstall your web application
please be aware that common php apps (joomla, wordpress and so on) are bugged and must be kept up-to-date
HTH

thanks Stefano, stopping www with service httpd-e-smith stop worked - no more mail queuing up!

as for deleting and reinstalling our web applications- this is something I've never done before.

we have about 15 webshares in /opt/webshare
as well as two ibays in /home/e-smith/files/ibays. /primary  and  /websitetwo

is there a way to pinpoint which of these are causing us issues? I'll be doing my best to search for the answer myself, but if someone knows off the top, I'm all ears.

[Stefano]

what was running in /primary and /websitetwo?

I would start from there

[mmccarn]

You can set your ibays to restrict access in /server-manager by setting 'Public access via web or anonymous ftp' to 'No access'.

There may be a similar setting for webshares.

If you disable access to all of your sites, you can re-enable httpd-e-smith and activate your sites one at a time to figure out which one has problems.

Record the current value of any setting you change so you can restore it after you're done fixing the problem.

There may also be something useful in /var/log/httpd/access_log or /var/log/messages (lots and lots of accesses to a specific web page, or from a specific IP address, for example).

[JasonS]

Thanks mmccarn and Stefano-- I hadn't had a chance to test your guys' ideas, but we may have solved it with some excellent help from Darrell May.

we ran the following to investigate changes in the last 30 days.

*Note*Our company webpage runs in the primary ibay and uses coldfusion.

find /home/e-smith/files/ibays –type f -mtime -30 –print
find /opt –type f -mtime -30 –print


here is the most interesting output:
/home/e-smith/files/ibays  <--only one change, a legit change on a web page text document announcing a new person.


/opt/wordpress/wp-content/themes/default/archives.php  <--edited last thursday>
/opt/wordpress/wp-content/themes/default/search.php  <--edited last thursday>
/opt/coldfusion8/ConnectorInstall0.txt
/opt/coldfusion8/wwwroot/WEB-INF/cfform/cache.dep
/opt/coldfusion8/wwwroot/WEB-INF/cfform/logs/flex.log
/opt/coldfusion8/runtime/logs/coldfusion-event.log
/opt/coldfusion8/runtime/lib/wsconfig/wsconfig_1.log
/opt/coldfusion8/runtime/lib/wsconfig/1/jrunserver.store
/opt/coldfusion8/runtime/lib/wsconfig/wsconfig.log
/opt/coldfusion8/logs/application.log/opt/coldfusion8/logs/server.log
/opt/coldfusion8/logs/exception.log
/opt/coldfusion8/logs/cfserver.log
/opt/coldfusion8/logs/eventgateway.log
/opt/coldfusion8/registry/cf.registry
/opt/coldfusion8/lib/neo-document.bak
/opt/coldfusion8/lib/license.properties
/opt/coldfusion8/lib/neo-datasource.xml
/opt/coldfusion8/lib/neo-drivers.bak
/opt/coldfusion8/lib/neo-cron.xml
/opt/coldfusion8/lib/neo-drivers.xml
/opt/coldfusion8/lib/neo-datasource.bak
/opt/coldfusion8/lib/client.properties
/opt/coldfusion8/lib/neo-cron.bak
/opt/coldfusion8/lib/neo-document.xml
/opt/openfire/conf/openfire.xml
/opt/openfire/conf/available-plugins.xml
/opt/openfire/conf/server-update.xml
/opt/openfire/logs/warn_3.log
/opt/openfire/logs/nohup.out
/opt/openfire/logs/info.log
/opt/openfire/logs/warn_2.log
/opt/openfire/logs/warn_4.log
/opt/openfire/logs/warn_1.log
/opt/openfire/logs/warn_5.log
/opt/openfire/logs/error.log
/opt/openfire/logs/warn.log


Interestingly, we don't use wordpress in our sites except for a very old and deprecated "emergency news" page that wasnt much more than a splash screen. It hadn't been updated with content since 2009.
The rest of the files in /opt/wordpress were from 2008 and 2009.

wordpress is owned by rpm
[root@mail webshare]# rpm -qf /opt/wordpress/wp-content/themes/default/archives.php
wordpress-2.6.2-1.el4.sme

I removed wordpress and removed the /opt/wordpress folder.
[root@mail ~]# rpm -e wordpress
error: Failed dependencies:
        wordpress is needed by (installed) smeserver-wordpress-1.0-2.el4.sme.noarch
[root@mail ~]# rpm -e smeserver-wordpress-1.0-2.el4.sme.noarch
[root@mail ~]# rpm -e wordpress
[root@mail /]# rm -Rf /opt/wordpress
[root@mail /]# signal-event post-upgrade; signal-event reboot


Unfortunately, before removing wordpress I turned the httpd service back on to see what wordpress content we might have had. When I turned httpd back on I expected qmail to get flooded again, but things stayed quiet. At that point I removed wordpress, so it's possibly too early to tell if wordpress was 100% the issue, and if there are any other compromises.

I will keep an eye on the queue to see if anything untowards happens down the road..
so far so good.

If you guys spot something I've missed or think there is something else for me to do, let me know. I really appreciate you taking the time to help- Thanks again!

now to go about alerting the ISP and other sites that our spam is cleaned up..

[JasonS]

I wanted to create a more concise post about the problem solving process we went through just in case it helps someone in the future...

Problem: qmail remote queue becoming very backed up. If we had more than 35000 messages in the queue, valid incoming email would fail to send to our internal exchange server.

check queue size via server-manager > mail log file analysis > summarize status of mail queue
OR 

[root@mail ~]# qmHandle -s
Total messages: 56818
Messages with local recipients: 0
Messages with remote recipients: 56812
Messages with bounces: 0
Messages in preprocess: 6

Stop qmail and qpsmtpd so you aren't spamming the world.

[root@mail ~]# sv d /service/qmail
[root@mail ~]# sv d /service/qpsmtpd

Check qmail to see if it stopped. It can be slow to stop. Wait five or ten minutes and it eventually will.
[root@mail ~]# sv s /service/qmail
run: /service/qmail: (pid 3987)

restart qmail and qpsmtpd later once you've found and fixed the issue.
[root@mail ~]# sv u /service/qmail
[root@mail ~]# sv u /service/qpsmtpd

What is in the queue?

[root@mail ~]# /var/qmail/bin/qmail-qread
18 Apr 2013 23:47:59 GMT  #929384  412  <anonymous@mydomain.com>
        remote  kapla@comcast.net

Next, analyze the message header to see if it was invoked by a process you can identify on your system:

[root@mail ~]# find /var/qmail/queue/mess/ -name 929384
/var/qmail/queue/mess/0/929384

[root@mail ~]# more /var/qmail/queue/mess/0/929384
Received: (qmail 24515 invoked by uid 102); 18 Apr 2013 23:47:59 -0000
Date: 18 Apr 2013 23:47:59 -0000
Message-ID: <20130418234759.24514.qmail@mydomain.com>
To: kapla@comcast.net
Subject: a bunch of spam garbage
From: lqtb@mydomain.com
Reply-To: lqtb@mydomain.com

Choosse  bbbestt VViaggra Pharmmcy online

Now take the uid number you see in the message header and search /etc/passwd to discover the owner.

[root@mail ~]# grep 102 /etc/passwd
www:x:102:102:e-smith web server:/home/e-smith:/bin/false

I can see that our web service owns the process and is generating the outgoing spam.
Stop the web service

[root@mail ~]# service httpd-e-smith stop

Now you want to clear out as much of the queue as you can before turning qmail and qpsmtpd back on to test if stopping httpd fixed your issue.
If your email was flowing into your mailbox on time, then chances are it's only spam in your queue and you can *mostly safely* run:

WARNING: ensure that qmail and qpsmtpd are stopped before deleting messages from the queue! see commands above

delete all messages from queue:
[root@mail ~]# qmHandle -D

Note: this will delete everything in your queue, including good mail if it was there.

If your queue was so choked that your email was not flowing properly, than don't do this. Reduce your queue by deleting messages by hand until you are below 10,000 messages. Then you can turn qmail back on so it can deliver the good messages. with the httpd service stopped you shouldn't be generating any more spam.

**remember to stop qmail and qpsmtpd before deleting messages from queue**

[root@mail ~]# /var/qmail/bin/qmail-qread
and copy the output so you can see what domains you are sending to. You should be able to get rid of a lot of messages this way:

delete emails in queue with matching text in the header:

[root@mail ~]# qmHandle -h'anonymous@mydomain.com'
[root@mail ~]# qmHandle -h'yahoo.com'
[root@mail ~]# qmHandle -h'aol.com'
etc.

Now your queue is clean'ish and you aren't generating more spam because httpd (or whichever process was the culprit) is turned off. You should be able to safely start qmail and qpstmpd again. keep an eye on it with [root@mail ~]# qmHandle -s


So, what might have changed recently to cause the issue?

In my case, we run a web page and some web shares on our server. I was able to run a search for files modified in the last 30 days. Our server and web page doesn't change much, so this was a pretty safe bet.

[root@mail ~]# find /home/e-smith/files/ibays –type f -mtime -30 –print > /root/ibay-changes.txt
[root@mail ~]# find /opt –type f -mtime -30 –print > /root/opt-changes.txt

review the .txt files for the output.

here is the most interesting output:

/opt/wordpress/wp-content/themes/default/archives.php  <--edited recently. timing coincides with spam.>
/opt/wordpress/wp-content/themes/default/search.php  <--edited recently.timing coincides with spam.>

Remove or fix the modules that you suspect. In my case, I removed wordpress. It was a 5 year old implementation that we weren't using. There was a live wordpress splash screen off our main web page that was likely targeted. I showed the removal process of wordpress in the message above this one.

after cleanup, ensure you perform whatever upgrade events are needed and ensure you restart or manually start httpd.

hope this helps someone else at some point.
cheers

[Stefano]

well done and thank you for sharing your experience..

[CharlieBrady]

Received: (qmail 10932 invoked by uid 102); 18 Apr 2013 12:28:49 -0000

Do:

grep 102 /etc/passwd

My guess is that will show 'www' - which will indicate that the mail messages are/were being generated by a script being run by your web server - probably a PHP application.

View /var/log/httpd/access_log from the time when the spam first started to be generated. You may find the accesses which were triggering your messages.

If you have PHP applications in your i-bays - remove them. Either that, or find and fix the problem (or problems) which is being exploited.

[CharlieBrady]

please be aware that common php apps (joomla, wordpress and so on) are bugged and must be kept up-to-date

Or removed.

[CharlieBrady]

*Note*Our company webpage runs in the primary ibay and uses coldfusion.

http://www.exploit-db.com/exploits/24946/

http://www.networkworld.com/news/2013/011613-adobe-patches-actively-exploited-coldfusion-265872.html

http://marc.info/?l=bugtraq&m=99678485232165

[purvis]

I had just read about Email Injection in web forms to produce spam email from the web server.
Maybe you have that. I am pretty sure it was in a paper back book called Php Solutions.
http://foundationphp.com/phpsolutions/

[purvis]

In that book on page 118. It speaks of Email Header Injection. 
This is a good book. I have of them.

[purvis]

How about the php security glitch in  7.6 as well.

[CharlieBrady]

How about the php security glitch in  7.6 as well.

What glitch is that? Please provide a reference.

[purvis]

http://forums.contribs.org/index.php/topic,48612.msg
CRITICAL exploit on CGI mode PHP

[CharlieBrady]

http://forums.contribs.org/index.php/topic,48612.msg
CRITICAL exploit on CGI mode PHP

PHP5 CGI is not part of SME 7.6.

[purvis]

That is a fine line not worth walking Charlie.
It is when you have the problem.
I remember warning saying to upgrade to sme 8.0 just because of the php glitch.

[CharlieBrady]

That is a fine line not worth walking Charlie.
It is when you have the problem.

I see no evidence that JasonS had/has PHP5 CGI installed.

[purvis]

You know the system way more than I Charlie and can diagnosis it better as well. I was just trying to remind about some possibilities of things. Better to swing in the dark than not at all.

[JasonS]

Thanks for the help Charlie - I had used your grep uid /etc/passwd instructions from another post/different thread.
It helped immensely.

You can see my whole resolution process in comment #13.
We are now 5 days spam free, queue functioning correctly with 0 messages stuck.

I believe it was out of date wordpress that was compromised.

[CharlieBrady]

You can see my whole resolution process in comment #13.

Thanks for so thoroughly documenting your diagnosis and cleanup process.

I believe it was out of date wordpress that was compromised.

Anyone with wordpress even a couple of months out of date should be looking closely at removing or updating it.