Unusual SPAM/discarded message on outbound mails

Discuss your pilot or production implementation with other Zimbra admins or our engineers.
Baylink
Outstanding Member
Outstanding Member
Posts: 381
Joined: Fri Sep 12, 2014 11:42 pm

Unusual SPAM/discarded message on outbound mails

Postby Baylink » Thu Jun 20, 2013 1:27 pm

On a 6.0.9 install that's been running fine for some years now (clearly :-), I'm suddenly having a problem with some outbound email originated from the web UI.
A message to one recipient with CC to three others, on 3 different domains (yahoo, 2 gmails, and a corporate email service) is generating 4 individual bounce messages in the servers maillog, which look like this:
Jun 20 10:43:45 benjamin postfix/smtp[29057]: 88B611F00302: to=, relay=127.0.0.1[127.0.0.1]:10024, delay=4.3, delays=0.01/0.01/0/4.3, dsn=2.7.0, status=sent (250 2.7.0 Ok, discarded, id=05742-15 - SPAM)
Each differs primarily in the to= address; the rest of the message is mostly identical, except for the ID. Notwithstanding "sent", the recipients don't seem to be getting the messages. Notably, even 250 2.7.0 is identical, which I would not necessarily expect if these were remote messages being perpetuated in my local log.
I've checked the server IP against a couple RBL lookups, and MXtoolbox's mail server checker; it's not an open relay, and no one has it blocked.
I can originate mail, apparently, to these recipients individually without getting the discarded message. The email in question has no attachments, and only a 2-level email forward cascade in it's body.
I'm a tad confused here; why would my own mailserver be marking *originating* mail (not even coming in via SMTPAUTH, say, from my cellphone's k-9) as spam, and dropping it? Any ideas?
Update: did check zmcontrol status, everything's marked as running.


Baylink
Outstanding Member
Outstanding Member
Posts: 381
Joined: Fri Sep 12, 2014 11:42 pm

Unusual SPAM/discarded message on outbound mails

Postby Baylink » Fri Jun 21, 2013 11:51 am

A message from one of the people to whom the outbound was sent; hard drop, didn't even make it into my junk folder:
Jun 21 10:56:48 benjamin postfix/qmgr[12334]: C300F1F00156: from=, size=133361, nrcpt=1 (queue active)

Jun 21 10:56:49 benjamin postfix/smtpd[17197]: disconnect from X3PPIR013.firstdata.com[208.72.254.11]

Jun 21 10:56:52 benjamin postfix/smtp[20833]: C300F1F00156: to=, relay=127.0.0.1[127.0.0.1]:10024, delay=5, delays=0.93/0/0/4.1, dsn=2.7.0, status=sent (250 2.7.0 Ok, discarded, id=11339-08 - SPAM)

Jun 21 10:56:52 benjamin postfix/qmgr[12334]: C300F1F00156: removed
Baylink
Outstanding Member
Outstanding Member
Posts: 381
Joined: Fri Sep 12, 2014 11:42 pm

Unusual SPAM/discarded message on outbound mails

Postby Baylink » Sat Jun 22, 2013 10:06 am

At the suggestion of someone on IRC, I've modified $log_level from 1 to 3 in amavisd.conf.in, and am restarting Zimbra; I think that's the proper protocol for this type of change, right?
I will then resend and see.
I have a sneaking suspicion I'm going to find that amavis/spamassassin isn't pulling proper updates anymore, and will either need to be upgraded, or will drive me off 6.0...
As another datapoint, while AS false positives on personal mail have been very rare, my system *has* been falsing positive more frequently on mailing list traffic for a year or two, just not enough to bother me.
And the false negative rate ain't too much fun either.
Baylink
Outstanding Member
Outstanding Member
Posts: 381
Joined: Fri Sep 12, 2014 11:42 pm

Unusual SPAM/discarded message on outbound mails

Postby Baylink » Tue Jun 25, 2013 9:21 am

Here's the amavis detail logging on this, from loglevel 3:
Jun 25 10:14:19 benjamin amavis[2401]: (02401-01) ESMTP::10024 /opt/zimbra/data/amavisd/tmp/amavis-20130625T101419-02401: -> ,,, SIZE=3643 Received: from benjamin.baylink.com ([127.0.0.1]) by localhost (benjamin.baylink.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP; Tue, 25 Jun 2013 10:14:19 -0400 (EDT)
Jun 25 10:14:19 benjamin amavis[2401]: (02401-01) Checking: QyFIem-GgV8A MYNETS [192.168.253.10] -> ,,,gregorykelly@yahoo.com>
Jun 25 10:14:23 benjamin amavis[2401]: (02401-01) Blocked SPAM, MYNETS LOCAL [192.168.253.10] [192.168.253.10] -> ,,,, Message-ID: , mail_id: QyFIem-GgV8A, Hits: 15.007, size: 3643, 4380 ms
Jun 25 10:14:23 benjamin amavis[2401]: (02401-01) TIMING [total 4381 ms] - ldap-prepare: 3 (0%)0, SMTP greeting: 2 (0%)0, SMTP EHLO: 1 (0%)0, SMTP pre-MAIL: 0 (0%)0, mkdir tempdir: 0 (0%)0, create email.txt: 0 (0%)0, ldap-connect: 32 (1%)1, lookup_ldap: 2 (0%)1, lookup_ldap: 2 (0%)1, lookup_ldap: 2 (0%)1, lookup_ldap: 2 (0%)1, SMTP pre-DATA-flush: 1 (0%)1, SMTP DATA: 0 (0%)1, check_init: 0(0%)1, digest_hdr: 1 (0%)1, digest_body_dkim: 0 (0%)1, gen_mail_id: 1 (0%)1, mkdir parts: 3 (0%)1, mime_decode: 7 (0%)1, get-file-type1: 11 (0%)2, decompose_part: 2 (0%)2, parts_decode: 0 (0%)2, check_header: 2 (0%)2, AV-scan-1: 5 (0%)2, spam-wb-list: 4 (0%)2, SA parse: 3 (0%)2, SA check: 4277 (98%)100, update_cache: 6 (0%)100, decide_mail_destiny: 3 (0%)100, prepare-dsn: 3 (0%)100, main_log_entry: 6 (0%)100, SMTP pre-response: 0 (0%)100, SMTP response: 0 (0%)100, unlink-1-files: 1 (0%)100, rundown: 1 (0%)100
Jun 25 10:14:23 benjamin amavis[2401]: (02401-01) extra modules loaded: /opt/zimbra/zimbramon/lib/i386-linux-thread-multi/auto/Net/SSLeay/autosplit.ix, /opt/zimbra/zimbramon/lib/i386-linux-thread-multi/auto/Net/SSLeay/randomize.al, IO/Socket/SSL.pm, Net/LDAP/Extension.pm, Net/SSLeay.pm
Jun 25 10:14:23 benjamin amavis[2401]: (02401-01) load: 100 %, total idle 0.000 s, busy 4.383 s
Annoyingly, this seems only to tell me about the timing, when I'm almost always not interesting in the timing so much as the contributions to spamminess -- or am I misunderstanding the format?
Baylink
Outstanding Member
Outstanding Member
Posts: 381
Joined: Fri Sep 12, 2014 11:42 pm

Unusual SPAM/discarded message on outbound mails

Postby Baylink » Tue Jun 25, 2013 10:42 am

Ok, upped logging to 5, set final_destiny to PASS, as suggested by sp00kz@irc; here's latest logging:
Jun 25 11:37:18 benjamin amavis[7628]: (07628-02-2) SEND via SMTP: <> -> ,ENVID=AM..20130625T153718Z@benjamin.baylink.com 250 2.0.0 Ok, id=07628-02-2, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as A2EA21F0031E
Jun 25 11:37:18 benjamin amavis[7628]: (07628-02-2) Blocked SPAM, MYNETS LOCAL [192.168.253.10] [192.168.253.10] -> ,,,, Message-ID: , mail_id: jLN96jf9u6aj, Hits: 17.707, size: 3814, 4129 ms
Jun 25 11:37:18 benjamin amavis[7628]: (07628-02-2) TIMING [total 4130 ms] - lookup_ldap: 3 (0%)0, lookup_ldap: 1 (0%)0, lookup_ldap: 1 (0%)0, lookup_ldap: 1 (0%)0, SMTP pre-DATA-flush: 1 (0%)0, SMTP DATA: 32 (1%)1, check_init: 0 (0%)1, digest_hdr: 1 (0%)1, digest_body_dkim: 0 (0%)1, gen_mail_id: 1 (0%)1, mime_decode: 7 (0%)1, get-file-type1: 11 (0%)1, decompose_part: 1 (0%)1, parts_decode: 0 (0%)1, check_header: 2 (0%)2, AV-scan-1: 5 (0%)2, spam-wb-list: 4 (0%)2, SA parse: 2 (0%)2, SA check: 4013 (97%)99, update_cache: 5 (0%)99, decide_mail_destiny: 3 (0%)99, prepare-dsn: 11 (0%)99, fwd-connect: 12 (0%)100, fwd-mail-pip: 2 (0%)100, fwd-rcpt-pip:0 (0%)100, fwd-data-chkpnt: 0 (0%)100, write-header: 0 (0%)100, fwd-data-contents: 2 (0%)100, fwd-end-chkpnt: 3 (0%)100, main_log_entry: 5 (0%)100, SMTP pre-response: 0 (0%)100, SMTP response: 0 (0%)100, unlink-1-files: 0 (0%)100, rundown: 0 (0%)100
Jun 25 11:37:18 benjamin postfix/smtp[7960]: 812701F00284: to=, relay=127.0.0.1[127.0.0.1]:10024, conn_use=2, delay=4.2, delays=0.02/0/0/4.1, dsn=2.5.0, status=sent (250 2.5.0 Ok, id=07628-02-2, BOUNCE)
Jun 25 11:37:18 benjamin amavis[7628]: (07628-02-2) idle_proc, 6: was busy, 4123.2 ms, total idle 38.005 s, busy 16.421 s
Jun 25 11:37:18 benjamin postfix/smtp[7960]: 812701F00284: to=, relay=127.0.0.1[127.0.0.1]:10024, conn_use=2, delay=4.2, delays=0.02/0/0/4.1, dsn=2.5.0, status=sent (250 2.5.0 Ok, id=07628-02-2, BOUNCE)
Jun 25 11:37:18 benjamin postfix/smtp[7960]: 812701F00284: to=, relay=127.0.0.1[127.0.0.1]:10024, conn_use=2,delay=4.2, delays=0.02/0/0/4.1, dsn=2.5.0, status=sent (250 2.5.0 Ok, id=07628-02-2, BOUNCE)
Jun 25 11:37:18 benjamin postfix/smtp[7960]: 812701F00284: to=, relay=127.0.0.1[127.0.0.1]:10024, conn_use=2, delay=4.2, delays=0.02/0/0/4.1, dsn=2.5.0, status=sent (250 2.5.0 Ok, id=07628-02-2, BOUNCE)
Jun 25 11:37:18 benjamin postfix/qmgr[7679]: 812701F00284: removed
Baylink
Outstanding Member
Outstanding Member
Posts: 381
Joined: Fri Sep 12, 2014 11:42 pm

Unusual SPAM/discarded message on outbound mails

Postby Baylink » Tue Jun 25, 2013 10:43 am

And here's the body of the bounce message I got in my inbox:
A message from

to: Wendy.Jelsone@bankofamericamerchant.com

to: phpninjass@gmail.com

to: lenwahl@hotmail.com

to: gregorykelly@yahoo.com
was considered unsolicited bulk e-mail (UBE).
Our internal reference code for your message is 07628-02-2/jLN96jf9u6aj
The message carried your return address, so it was either a genuine mail

from you, or a sender address was faked and your e-mail address abused

by third party, in which case we apologize for undesired notification.
We do try to minimize backscatter for more prominent cases of UBE and

for infected mail, but for less obvious cases some balance between

losing genuine mail and sending undesired backscatter is sought,

and there can be some collateral damage on either side.
First upstream SMTP client IP address: [192.168.253.10] benjamin.baylink.com

According to a 'Received:' trace, the message apparently originated at:

[192.168.253.10], benjamin.baylink.com benjamin.baylink.com [192.168.253.10]
Return-Path:

From: Jay Ashworth

Message-ID:

Subject: RESEND Re: Clientline login
Delivery of the email was stopped!
Baylink
Outstanding Member
Outstanding Member
Posts: 381
Joined: Fri Sep 12, 2014 11:42 pm

Unusual SPAM/discarded message on outbound mails

Postby Baylink » Tue Jun 25, 2013 12:55 pm

Well, it turns out after extracting the message and running SA manually, that SA was *telling us* what was bouncing it, but Zimbra was discarding that, rather than including it in the bounce.
It was
1) The fact that my bloghost appears in some RBLs

2) The fact that their website/application URL appears in *several* RBLs

and

3) The fact that Zimbra is completely improperly calling the IP address from which I was logged into the ZWC a "relay", and passing that into SA as well. (It's my Sprint 4G phone.)
The last is a formal bug, but may be fixed in later releases already.
User avatar
quanah
Zimbra Alumni
Zimbra Alumni
Posts: 1667
Joined: Fri Sep 12, 2014 10:33 pm
Contact:

Unusual SPAM/discarded message on outbound mails

Postby quanah » Tue Jun 25, 2013 2:37 pm

I believe item#3 is fixed in ZCS8. You may wish to look at upgrading to ZCS 8.0.4.
--
Quanah Gibson-Mount
Product Architect, Symas http://www.symas.com/
OpenLDAP Core team http://www.openldap.org/project/
Baylink
Outstanding Member
Outstanding Member
Posts: 381
Joined: Fri Sep 12, 2014 11:42 pm

Unusual SPAM/discarded message on outbound mails

Postby Baylink » Tue Jun 25, 2013 9:10 pm

I may do that, but I heard some passing IRC chatter that bring the mailbase along can be troublesome; any clean info on that?
User avatar
quanah
Zimbra Alumni
Zimbra Alumni
Posts: 1667
Joined: Fri Sep 12, 2014 10:33 pm
Contact:

Unusual SPAM/discarded message on outbound mails

Postby quanah » Wed Jun 26, 2013 11:08 am

I've no idea what your question means, sorry. Can you elaborate?
Thanks,

Quanah
--
Quanah Gibson-Mount
Product Architect, Symas http://www.symas.com/
OpenLDAP Core team http://www.openldap.org/project/

Return to “Administrators”

Who is online

Users browsing this forum: Google [Bot], MSN [Bot] and 10 guests