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=<[email protected]>, size=145530, nrcpt=1 (queue active)
Oct 25 11:52:20 mailbox postfix/smtp[53011]: 1CD504D13C96: to=<[email protected]>, 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=<[email protected]>
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=<[email protected]>, 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, "[email protected]" matches, result="smtp:[127.0.0.1]:10025", matching_key="(opaque:smtp:[127.0.0.1]:10025)"
delivery method is 1, recips: [email protected]
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, <[email protected]>
lookup: (scalar) matches, result="-100"
lookup [spam_dsn_cutoff_level_bysender] => true, "[email protected]" matches, result="-100", matching_key="(constant:-100)"
dsn: . 554 Spam <[email protected]> -> <[email protected]>: 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: <[email protected]> -> <[email protected]>
delivery_status_notification: notif 0 bytes, suppressed: no
one_response_for_all, per_recip_capable: N, suppressed: N
one_response_for_all <[email protected]>: 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, [email protected], smtputf8
oldest_public_ip_addr_from_received: 178.17.170.60
Blocked SPAM {RejectedInbound}, [85.25.13.92]:44462 [178.17.170.60] <[email protected]> -> <[email protected]>, 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.
The problem here is that it's amavis, not postfix, that's rejecting the message. Here's the standard flow for incoming messages:
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=<[email protected]>, 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.
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_backupsmtpd pass - - n - - smtpdJust below that line you should add:
-o smtpd_proxy_filter=127.0.0.1:10024find 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.
chflags uchg /Library/Server/Mail/config/postfix/master.cfafter that restart the mail server
serveradmin stop mail; serveradmin start mailand watch your mail logs for a while to make sure you did everything right:tail -f /var/log/mail.logand only in case you want to change/adjust the configuration:
chflags nouchg /Library/Server/Mail/config/postfix/master.cfHope this helps someone running a postfix mail server on OS X.