2

This is a stock OS X 5.2 Server mail configuration which I'm trying to change to make it reject a spam message with a "554 5.7.0 Reject" before accepting it without sending out any additional non-delivery notifications to the sender. It's configured to accept spam with a "250 2.7.0 Ok" and later discard or quarantine it out of the box. That is usually done with 

$final_spam_destiny       = D_REJECT;
$warnspamsender = 0; (probably not necessary)

and can be fine-tuned using

$sa_dsn_cutoff_level = X;
$sa_crediblefrom_dsn_cutoff_level = X;

The problem I'm having is that despite those cutoff levels being way less than the actual spam score for a particular message, the DSN/bounce still gets through. It looks like this:

Oct 25 11:52:18 mailbox postfix/smtpd[52962]: 1CD504D13C96: client=mail.informark.co.ua[85.25.13.92]
Oct 25 11:52:18 mailbox postfix/cleanup[53010]: 1CD504D13C96: message-id=<11a201d22e97$126f7740$2adb3d4f@ynmyfnj>
Oct 25 11:52:19 mailbox postfix/qmgr[52740]: 1CD504D13C96: from=<ynmyfnj@informark.co.ua>, size=145530, nrcpt=1 (queue active)
Oct 25 11:52:20 mailbox postfix/smtp[53011]: 1CD504D13C96: to=<xxx@xxx.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=2.2, delays=1.1/0/0.02/1, dsn=5.7.0, status=bounced (host 127.0.0.1[127.0.0.1] said: 554 5.7.0 Reject, id=52765-01 - spam (in reply to end of DATA command))
Oct 25 11:52:20 mailbox postfix/bounce[53022]: 1CD504D13C96: sender non-delivery notification: 4B9804D13CB0
Oct 25 11:52:20 mailbox postfix/qmgr[52740]: 1CD504D13C96: removed

Oct 25 11:52:20 mailbox postfix/cleanup[53010]: 4B9804D13CB0: message-id=<20161025085220.4B9804D13CB0@xxx.xxx.com>
Oct 25 11:52:20 mailbox postfix/qmgr[52740]: 4B9804D13CB0: from=<>, size=3019, nrcpt=1 (queue active)
Oct 25 11:52:20 mailbox postfix/bounce[53022]: 1CD504D13C96: sender non-delivery notification: 4B9804D13CB0
Oct 25 11:52:20 mailbox postfix/smtp[53015]: 4B9804D13CB0: to=<ynmyfnj@informark.co.ua>, relay=mail.informark.co.ua[85.25.13.92]:25, delay=0.58, delays=0/0/0.26/0.32, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 9145D8C8CCC)
Oct 25 11:52:20 mailbox postfix/qmgr[52740]: 4B9804D13CB0: removed

and the relevant part from amavis.log (debug level 5) looks like so:

lookup [forward_method] => true,  "xxx@xxx.com" matches, result="smtp:[127.0.0.1]:10025", matching_key="(opaque:smtp:[127.0.0.1]:10025)"
delivery method is 1, recips: xxx@xxx.com
get_deadline quar+notif - deadline in 479.0 s, set to 288.000 s
prolong_timer quar+notif: timer 288, was 288, deadline in 479.0 s
DSN: sender NOT credible, SA: 15.417, <ynmyfnj@informark.co.ua>
lookup: (scalar) matches, result="-100"
lookup [spam_dsn_cutoff_level_bysender] => true,  "ynmyfnj@informark.co.ua" matches, result="-100", matching_key="(constant:-100)"
dsn: . 554 Spam <ynmyfnj@informark.co.ua> -> <xxx@xxx.com>: on_succ=0, on_dly=1, on_fail=1, never=0, warn_sender=, DSN_passed_on=, destiny=-3, mta_resp: "554 5.7.0 Reject, id=52765-01 - spam"
DSN: FAIL . 554 Spam, status propagated back: <ynmyfnj@informark.co.ua> -> <xxx@xxx.com>
delivery_status_notification: notif 0 bytes, suppressed: no
one_response_for_all, per_recip_capable: N, suppressed: N
one_response_for_all <ynmyfnj@informark.co.ua>: REJECTs, '554 5.7.0 Reject, id=52765-01 - spam'
notif=N, suppressed=0, ndn_needed=, exit=69, 554 5.7.0 Reject, id=52765-01 - spam
get_deadline delivery-notification - deadline in 479.0 s, set to 288.000 s
prolong_timer delivery-notification: timer 288, was 288, deadline in 479.0 s
status counters: InMsgsStatus{Rejected,RejectedInbound}
get_deadline snmp-counters - deadline in 479.0 s, set to 288.000 s
prolong_timer snmp-counters: timer 288, was 288, deadline in 479.0 s
orcpt_encode rfc822, xxx@xxx.com, smtputf8
oldest_public_ip_addr_from_received: 178.17.170.60
Blocked SPAM {RejectedInbound}, [85.25.13.92]:44462 [178.17.170.60] <ynmyfnj@informark.co.ua> -> <xxx@xxx.com>, Queue-ID: 1CD504D13C96, Message-ID: <11a201d22e97$126f7740$2adb3d4f@ynmyfnj>, mail_id: N0710n9hpdxw, Hits: 15.417, size: 145530, 1021 ms
get_deadline main_log_entry - deadline in 479.0 s, set to 288.000 s
prolong_timer main_log_entry: timer 288, was 288, deadline in 479.0 s
TIMING-SA total 817 ms - parse: 8 (1.0%), extract_message_metadata: 55 (6.7%), get_uri_detail_list: 1.42 (0.2%), tests_pri_-1000: 32 (3.9%), tests_pri_-950: 1.05 (0.1%), tests_pri_-900: 1.13 (0.1%), tests_pri_-400: 26 (3.1%), check_bayes: 24 (2.9%), b_tokenize: 11 (1.3%), b_tok_get_all: 3.5 (0.4%), b_comp_prob: 4.4 (0.5%), b_tok_touch_all: 0.80 (0.1%), b_finish: 1.12 (0.1%), tests_pri_0: 665 (81.4%), check_dkim_adsp: 479 (58.6%), check_spf: 43 (5.3%), poll_dns_idle: 0.28 (0.0%), check_pyzor: 0.25 (0.0%), tests_pri_500: 5 (0.7%), get_report: 0.77 (0.1%)
updating snmp variables in BDB
get_deadline check done - deadline in 479.0 s, set to 288.000 s
prolong_timer check done: timer 288, was 288, deadline in 479.0 s
sending SMTP response: "554 5.7.0 Reject, id=52765-01 - spam"
ESMTP> 554 5.7.0 Reject, id=52765-01 - spam
...
ESMTP< QUIT\r\n
...
ESMTP> 221 2.0.0 [127.0.0.1] amavisd-new closing transmission channel

As a result despite explicitly telling amavis/postfix NOT to send out a bounce to a faked email address and even amavis acknowledging my wish there, the bounces still get sent out. I presume the key in the logs is the word "suppressed" which is "no" and "0" instead of "yes" and "1" as I have seen in the amavis logs elsewhere on the internet.

So the question is what I'm doing wrong and whether there could be something else interfering with the setup and I'd also like to know the best way to debug this. Obviously the statements in the amavis log are contradictory.

Захар Joe
  • 142
  • 1
  • 10

2 Answers2

2

The problem here is that it's amavis, not postfix, that's rejecting the message. Here's the standard flow for incoming messages:

  1. postfix receives the message from the sending MTA (or spambot)
  2. postfix forwards (or attempts to forward) the message to amaviz (on port 10024)
  3. amaviz forwards the message back to postfix
  4. postfix delivers the message to cyrus (which handles the mailboxes on OS X server)

What's going on in your case is that postfix is receiving the message (step 1), but amaviz rejects it (at step 2), so postfix generates a bounce message. See the log entries like "to=<xxx@xxx.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=2.2, delays=1.1/0/0.02/1, dsn=5.7.0, status=bounced (host 127.0.0.1[127.0.0.1] said: 554 5.7.0 Reject, id=52765-01 - spam (in reply to end of DATA command))". Note that it's postfix sending to localhost:10024 (amaviz), and postfix is the MTA getting the 554 reject.

Once postfix has received the message, it's too late to reject it; you can really only drop it or pass it. This is why black- and grey-listing are useful; they're not as precise as a content scanner, but they get applied by postfix before it's received the message, and therefore allow a true reject.

Gordon Davisson
  • 11,036
  • 3
  • 27
  • 33
  • Yes, it all makes sense now, thank you for clarifying how mail proceeds in the chain and pointing out the relevant part in the postfix log. But anyway, I'm curious to know if postfix could be configured in some way to respond with a 5.7.0 after DATA and _before_ closing that particular connection/session. – Захар Joe Oct 26 '16 at 12:35
  • @ЗахарJoe: That is possible using postfix's ["milter" (mail filter) support](http://www.postfix.org/MILTER_README.html). I haven't used this, so I can't really give you any advice on it. – Gordon Davisson Oct 26 '16 at 15:05
1

The solution to enabling before-queue filtering with amavisd-new on OS X 10.11 is quite simple as most of the work has already been done by Apple, so here it is in case anyone wants to implement it on their own OS X Server. This page helped me get through it.

Three things need to be done, but first, back up your configuration files! You can do that with

cp -Rp /Library/Server/Mail/config /Library/Server/Mail/config_backup

  1. /Library/Server/Mail/config/postfix/master.cf needs to be edited. Find the line that contains

smtpd pass - - n - - smtpd

Just below that line you should add:

-o smtpd_proxy_filter=127.0.0.1:10024

  1. /Library/Server/Mail/config/amavisd/amavisd.conf needs to be edited.

find the line

$final_spam_destiny = D_DISCARD;

and replace it with

$final_spam_destiny = D_REJECT;

You can set D_REJECT for $final_virus_destiny as well.

  1. Set the user-immutable flag on master.cf as OS X's serveradmin will rewrite the file on next mail server restart:

chflags uchg /Library/Server/Mail/config/postfix/master.cf

after that restart the mail server

serveradmin stop mail; serveradmin start mail and watch your mail logs for a while to make sure you did everything right:

tail -f /var/log/mail.log

and only in case you want to change/adjust the configuration:

chflags nouchg /Library/Server/Mail/config/postfix/master.cf

Hope this helps someone running a postfix mail server on OS X.

Захар Joe
  • 142
  • 1
  • 10