From: Pawe³ Le¶niak (warlordlesniakowie.com)
Date: Thu Apr 24 2008 - 02:04:34 CDT

• Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

> reject_unlisted_recipient is unlikely to help, but it's hard to tell
> from the info you posted exactly what the problem might be.
>
> Please show us "postconf -n" output, complete log entries showing the
> unwanted rejection, and sample contents of your recipient map file.
OK, but I have to describe my problem in different way than.

My two servers have very similar configuration. On one (working server),
check_policy_service works great. On second - spawn never show up.
Here's excerpt from main.cf:

Working server:
smtpd_recipient_restrictions =
  reject_unauth_pipelining,
  reject_unknown_sender_domain,
  reject_unknown_recipient_domain,
  permit_mynetworks,
  permit_sasl_authenticated,
  reject_unauth_destination,
  check_recipient_access hash:/etc/postfix/restricted_recipients.map,
  check_policy_service inet:127.0.0.1:60000
  check_policy_service unix:private/policy
  permit

Not working server:
smtpd_recipient_restrictions =
   reject_unauth_pipelining,
   permit_mynetworks,
   permit_sasl_authenticated,
   reject_unauth_destination,
   reject_unknown_sender_domain,
   reject_unknown_recipient_domain,
   check_recipient_access hash:/etc/postfix/restricted_recipients.map,
   reject_unlisted_recipient,
   check_policy_service inet:127.0.0.1:60000,
   check_policy_service unix:private/policy,
   permit

As you can see, in first configuration there's no
reject_unlisted_recipient option. Now to be clear, in
restricted_recipients.map I have all my local email accounts permitted
(ex. warlordexample.com OK). And I believe when my email is permitted
by rule check_recipient_access, check_policy_service should not take
place - but it does. Correct me if I'm wrong (I'm a postfix newbie).
After some testings it looks like changing OK to DUNNO in
check_policy_service on not_working server does the job - mail is being
checked by check_policy_services (both). Now if I remove my email
completely from this (restricted_recipients.map) table, emails coming to
my address are always rejected with
Apr 23 09:19:10 www postfix/smtpd[14501]: NOQUEUE: reject: RCPT from
lola.ifmpan.poznan.pl[150.254.201.18]: 554 5.7.1 <warlordexample.com>:
Recipient address rejected: Access denied;
from=<warlordlesniakowie.com> to=<warlordexample.com> proto=ESMTP
helo=<mail.lesniakowie.com>
Where warlordexample.com is my email address on not working server.

Now when you're surprised with my question about
reject_unlisted_recipient, I've checked and it doesn't matter on
not_working server if there's reject_unlisted_recipient option or not -
if email is permitted by OK, no further tests are made.

So my very backward question is why "working server" goes to checking
policies even when recipient is permitted by a rule?

Here's my postconf -n output.
Working server (which in my opinion is not working correctly):
address_verify_map = btree:/etc/postfix/address_verify
alias_database = $alias_maps
alias_maps = hash:/etc/postfix/aliases
bounce_queue_lifetime = 3d
bounce_size_limit = 50000
broken_sasl_auth_clients = yes
canonical_maps = hash:/etc/postfix/canonical
command_directory = /usr/sbin
config_directory = /etc/postfix
content_filter = smtp-amavis:[127.0.0.1]:10024
daemon_directory = /usr/lib/postfix
data_directory = /var/lib/postfix
debug_peer_level = 2
debug_peer_list = 127.0.0.1
header_checks = regexp:/etc/postfix/header_checks
header_size_limit = 102400
html_directory = no
local_recipient_maps = proxy:unix:passwd.byname $alias_maps
mail_owner = mail
mailbox_command = /usr/bin/procmail -f- -a "$USER"
mailbox_size_limit = 1512000000
mailq_path = /usr/bin/mailq
manpage_directory = /usr/man
masquerade_domains = !anothersmtphost.working.com working.com
maximal_queue_lifetime = 3d
message_size_limit = 250000000
mydestination = mail.working.com, working.com, smtp2.working.com
mydomain = working.com
myhostname = mail.working.com
mynetworks = 127.0.0.0/8, DDD.DDD.DDD.DDD/32
myorigin = $mydomain
newaliases_path = /usr/bin/newaliases
queue_directory = /var/spool/postfix
queue_minfree = 1024000000
queue_run_delay = 10m
readme_directory = no
sample_directory = /etc/postfix
sendmail_path = /usr/sbin/sendmail
setgid_group = postdrop
smtpd_client_restrictions = check_client_access
hash:/etc/postfix/blackwhite.map, reject_unknown_sender_domain,
permit_mynetworks, reject_rbl_client sbl.spamhaus.org,
reject_rbl_client bl.spamcop.net, permit
smtpd_error_sleep_time = 60
smtpd_hard_error_limit = 10
smtpd_recipient_limit = 50
smtpd_recipient_restrictions = reject_unauth_pipelining,
reject_unknown_sender_domain, reject_unknown_recipient_domain,
permit_mynetworks, permit_sasl_authenticated,
reject_unauth_destination, check_recipient_access
hash:/etc/postfix/restricted_recipients.map, check_policy_service
inet:127.0.0.1:60000 check_policy_service unix:private/policy permit
smtpd_sasl_auth_enable = yes
smtpd_sasl_security_options = noanonymous
smtpd_sender_restrictions = check_sender_access
hash:/etc/postfix/restricted_senders.map,
reject_sender_login_mismatch, reject_unknown_sender_domain,
reject_unauthenticated_sender_login_mismatch, warn_if_reject
reject_unverified_sender, permit
smtpd_soft_error_limit = 60
unknown_local_recipient_reject_code = 550

And broken one (which I think works OK if permitted recipient shouldn't
be checked by rules following it):
address_verify_map = btree:/etc/postfix/address_verify
alias_database = $alias_maps
alias_maps = hash:/etc/postfix/aliases
bounce_queue_lifetime = 3d
bounce_size_limit = 50000
broken_sasl_auth_clients = yes
command_directory = /usr/sbin
config_directory = /etc/postfix
content_filter = smtp-amavis:[127.0.0.1]:10024
daemon_directory = /usr/lib/postfix
debug_peer_level = 1
disable_vrfy_command = yes
header_checks = regexp:/etc/postfix/header_checks
header_size_limit = 102400
html_directory = no
local_recipient_maps = proxy:unix:passwd.byname $alias_maps
mail_owner = mail
mailbox_command = /usr/bin/procmail -f- -a "$USER"
mailbox_size_limit = 512000000
mailq_path = /usr/bin/mailq
manpage_directory = /usr/man
masquerade_domains = drewno.pl
maximal_queue_lifetime = 3d
message_size_limit = 51200000
mydestination = mail.example.com, example.com, localhost
mydomain = example.com
myhostname = mail.example.com
mynetworks = 127.0.0.0/8, DDD.DDD.DDD.DDD/32
myorigin = $mydomain
newaliases_path = /usr/bin/newaliases
queue_directory = /var/spool/postfix
queue_minfree = 1024000000
queue_run_delay = 10m
readme_directory = no
sample_directory = /etc/postfix
sendmail_path = /usr/sbin/sendmail
setgid_group = postdrop
smtpd_client_restrictions = check_client_access
hash:/etc/postfix/blackwhite.map, reject_unknown_sender_domain,
permit_mynetworks, reject_rbl_client sbl.spamhaus.org, permit
smtpd_error_sleep_time = 60
smtpd_hard_error_limit = 10
smtpd_recipient_limit = 20
smtpd_recipient_restrictions = reject_unauth_pipelining,
permit_mynetworks, permit_sasl_authenticated,
reject_unauth_destination, reject_unknown_sender_domain,
reject_unknown_recipient_domain, check_recipient_access
hash:/etc/postfix/restricted_recipients.map,
reject_unlisted_recipient, check_policy_service
inet:127.0.0.1:60000, check_policy_service unix:private/policy,
permit
smtpd_sasl_auth_enable = yes
smtpd_sasl_security_options = noanonymous
smtpd_sender_restrictions = check_sender_access
hash:/etc/postfix/restricted_senders.map,
reject_sender_login_mismatch, reject_unknown_sender_domain,
reject_unauthenticated_sender_login_mismatch, warn_if_reject
reject_unverified_sender, permit
smtpd_soft_error_limit = 60
unknown_local_recipient_reject_code = 550

On both servers restricted_recipients.map consist of all local emails
followed by OK (so they are permitted by check_recipient_access I guess).
(ex.:
-- not working server
example.com REJECT
mail.example.com REJECT
warlordexample.com OK
user2example.com OK
...
-- working server
working.com REJECT
mail.working.com REJECT
warlordworking.com OK
user3working.com OK
...
)

There's nothing to see unfortunately in log file. It's just there are
missing entries showing that check_policy_service takes place.

Here goes one example SMTP session from not working server:

Apr 22 22:43:59 www postfix/smtpd[24757]: connect frdom
lola.ifmpan.poznan.pl[150.254.201.18]
Apr 22 22:43:59 www postfix/smtpd[24757]: 83C8B288:
client=lola.ifmpan.poznan.pl[150.254.201.18]
Apr 22 22:43:59 www postfix/cleanup[24762]: 83C8B288:
message-id=<480E4DB6.5020005lesniakowie.com>
Apr 22 22:43:59 www postfix/smtpd[24757]: disconnect from
lola.ifmpan.poznan.pl[150.254.201.18]
Apr 22 22:43:59 www postfix/qmgr[24743]: 83C8B288:
from=<warlordlesniakowie.com>, size=1233, nrcpt=1 (queue active)
Apr 22 22:43:59 www postfix/smtp[24763]: < 127.0.0.1[127.0.0.1]: 220
[127.0.0.1] ESMTP amavisd-new service ready
Apr 22 22:43:59 www postfix/smtp[24763]: > 127.0.0.1[127.0.0.1]: EHLO
mail.example.com
Apr 22 22:43:59 www postfix/smtp[24763]: < 127.0.0.1[127.0.0.1]:
250-[127.0.0.1]
Apr 22 22:43:59 www postfix/smtp[24763]: < 127.0.0.1[127.0.0.1]: 250-VRFY
Apr 22 22:43:59 www postfix/smtp[24763]: < 127.0.0.1[127.0.0.1]:
250-PIPELINING
Apr 22 22:43:59 www postfix/smtp[24763]: < 127.0.0.1[127.0.0.1]: 250-SIZE
Apr 22 22:43:59 www postfix/smtp[24763]: < 127.0.0.1[127.0.0.1]:
250-ENHANCEDSTATUSCODES
Apr 22 22:43:59 www postfix/smtp[24763]: < 127.0.0.1[127.0.0.1]:
250-8BITMIME
Apr 22 22:43:59 www postfix/smtp[24763]: < 127.0.0.1[127.0.0.1]: 250-DSN
Apr 22 22:43:59 www postfix/smtp[24763]: < 127.0.0.1[127.0.0.1]: 250
XFORWARD NAME ADDR PROTO HELO
Apr 22 22:43:59 www postfix/smtp[24763]: server features: 0x978f size 0
Apr 22 22:43:59 www postfix/smtp[24763]: Using ESMTP PIPELINING, TCP
send buffer size is 4096
Apr 22 22:43:59 www postfix/smtp[24763]: > 127.0.0.1[127.0.0.1]:
XFORWARD NAME=lola.ifmpan.poznan.pl ADDR=150.254.201.18
Apr 22 22:43:59 www postfix/smtp[24763]: > 127.0.0.1[127.0.0.1]:
XFORWARD PROTO=ESMTP HELO=mail.lesniakowie.com
Apr 22 22:43:59 www postfix/smtp[24763]: > 127.0.0.1[127.0.0.1]: MAIL
FROM:<warlordlesniakowie.com> SIZE=1233 BODY=7BIT
Apr 22 22:43:59 www postfix/smtp[24763]: > 127.0.0.1[127.0.0.1]: RCPT
TO:<warlordexample.com> ORCPT=rfc822;warlordexample.com
Apr 22 22:43:59 www postfix/smtp[24763]: > 127.0.0.1[127.0.0.1]: DATA
Apr 22 22:43:59 www postfix/smtp[24763]: < 127.0.0.1[127.0.0.1]: 250
2.5.0 Ok XFORWARD
Apr 22 22:43:59 www postfix/smtp[24763]: < 127.0.0.1[127.0.0.1]: 250
2.5.0 Ok XFORWARD
Apr 22 22:43:59 www postfix/smtp[24763]: < 127.0.0.1[127.0.0.1]: 250
2.1.0 Sender <warlordlesniakowie.com> OK
Apr 22 22:43:59 www postfix/smtp[24763]: < 127.0.0.1[127.0.0.1]: 250
2.1.5 Recipient <warlordexample.com> OK
Apr 22 22:43:59 www postfix/smtp[24763]: < 127.0.0.1[127.0.0.1]: 354 End
data with <CR><LF>.<CR><LF>
Apr 22 22:43:59 www postfix/smtp[24763]: > 127.0.0.1[127.0.0.1]: .
Apr 22 22:43:59 www postfix/smtp[24763]: > 127.0.0.1[127.0.0.1]: QUIT
Apr 22 22:44:01 www postfix/smtpd[24767]: connect from unknown[127.0.0.1]
Apr 22 22:44:01 www postfix/smtpd[24767]: match_hostname: unknown ~?
127.0.0.0/8
Apr 22 22:44:01 www postfix/smtpd[24767]: match_hostaddr: 127.0.0.1 ~?
127.0.0.0/8
Apr 22 22:44:01 www postfix/smtpd[24767]: > unknown[127.0.0.1]: 220
mail.example.com ESMTP Postfix
Apr 22 22:44:01 www postfix/smtpd[24767]: < unknown[127.0.0.1]: EHLO
localhost
Apr 22 22:44:01 www postfix/smtpd[24767]: > unknown[127.0.0.1]:
250-mail.example.com
Apr 22 22:44:01 www postfix/smtpd[24767]: > unknown[127.0.0.1]:
250-PIPELINING
Apr 22 22:44:01 www postfix/smtpd[24767]: > unknown[127.0.0.1]: 250-SIZE
51200000
Apr 22 22:44:01 www postfix/smtpd[24767]: > unknown[127.0.0.1]: 250-ETRN
Apr 22 22:44:01 www postfix/smtpd[24767]: > unknown[127.0.0.1]: 250-AUTH
LOGIN PLAIN
Apr 22 22:44:01 www postfix/smtpd[24767]: match_list_match: unknown: no
match
Apr 22 22:44:01 www postfix/smtpd[24767]: match_list_match: 127.0.0.1:
no match
Apr 22 22:44:01 www postfix/smtpd[24767]: > unknown[127.0.0.1]:
250-AUTH=LOGIN PLAIN
Apr 22 22:44:01 www postfix/smtpd[24767]: > unknown[127.0.0.1]:
250-ENHANCEDSTATUSCODES
Apr 22 22:44:01 www postfix/smtpd[24767]: > unknown[127.0.0.1]: 250-8BITMIME
Apr 22 22:44:01 www postfix/smtpd[24767]: > unknown[127.0.0.1]: 250 DSN
Apr 22 22:44:01 www postfix/smtpd[24767]: < unknown[127.0.0.1]: MAIL
FROM:<warlordlesniakowie.com> BODY=7BIT
Apr 22 22:44:01 www postfix/smtpd[24767]: extract_addr: input:
<warlordlesniakowie.com>
Apr 22 22:44:01 www postfix/smtpd[24767]: smtpd_check_addr:
addr=warlordlesniakowie.com
Apr 22 22:44:01 www postfix/smtpd[24767]: connect to subsystem
private/rewrite
Apr 22 22:44:01 www postfix/smtpd[24767]: send attr request = rewrite
Apr 22 22:44:01 www postfix/smtpd[24767]: send attr rule = local
Apr 22 22:44:01 www postfix/smtpd[24767]: send attr address =
warlordlesniakowie.com
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: flags
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: flags
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value: 0
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: address
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: address
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value:
warlordlesniakowie.com
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: (list terminator)
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: (end)
Apr 22 22:44:01 www postfix/smtpd[24767]: rewrite_clnt: local:
warlordlesniakowie.com -> warlordlesniakowie.com
Apr 22 22:44:01 www postfix/smtpd[24767]: send attr request = resolve
Apr 22 22:44:01 www postfix/smtpd[24767]: send attr sender =
Apr 22 22:44:01 www postfix/smtpd[24767]: send attr address =
warlordlesniakowie.com
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: flags
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: flags
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value: 0
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: transport
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: transport
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value: smtp
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: nexthop
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: nexthop
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value:
lesniakowie.com
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: recipient
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: recipient
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value:
warlordlesniakowie.com
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: flags
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: flags
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value: 4096
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: (list terminator)
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: (end)
Apr 22 22:44:01 www postfix/smtpd[24767]: resolve_clnt: `' ->
`warlordlesniakowie.com' -> transp=`smtp' host=`lesniakowie.com'
rcpt=`warlordlesniakowie.com' flags= class=default
Apr 22 22:44:01 www postfix/smtpd[24767]: ctable_locate: install entry
key warlordlesniakowie.com
Apr 22 22:44:01 www postfix/smtpd[24767]: extract_addr: in:
<warlordlesniakowie.com>, result: warlordlesniakowie.com
Apr 22 22:44:01 www postfix/smtpd[24767]: fsspace: .: block size 4096,
blocks free 7245326
Apr 22 22:44:01 www postfix/smtpd[24767]: smtpd_check_queue: blocks 4096
avail 7245326 min_free 1024000000 msg_size_limit 51200000
Apr 22 22:44:01 www postfix/smtpd[24767]: > unknown[127.0.0.1]: 250 2.1.0 Ok
Apr 22 22:44:01 www postfix/smtpd[24767]: < unknown[127.0.0.1]: RCPT
TO:<warlordexample.com> ORCPT=rfc822;warlordexample.com
Apr 22 22:44:01 www postfix/smtpd[24767]: extract_addr: input:
<warlordexample.com>
Apr 22 22:44:01 www postfix/smtpd[24767]: smtpd_check_addr:
addr=warlordexample.com
Apr 22 22:44:01 www postfix/smtpd[24767]: send attr request = rewrite
Apr 22 22:44:01 www postfix/smtpd[24767]: send attr rule = local
Apr 22 22:44:01 www postfix/smtpd[24767]: send attr address =
warlordexample.com
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: flags
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: flags
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value: 0
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: address
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: address
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value:
warlordexample.com
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: (list terminator)
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: (end)
Apr 22 22:44:01 www postfix/smtpd[24767]: rewrite_clnt: local:
warlordexample.com -> warlordexample.com
Apr 22 22:44:01 www postfix/smtpd[24767]: send attr request = resolve
Apr 22 22:44:01 www postfix/smtpd[24767]: send attr sender =
Apr 22 22:44:01 www postfix/smtpd[24767]: send attr address =
warlordexample.com
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: flags
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: flags
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value: 0
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: transport
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: transport
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value: local
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: nexthop
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: nexthop
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value:
mail.example.com
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: recipient
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: recipient
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value:
warlordexample.com
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: flags
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: flags
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value: 256
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: (list terminator)
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: (end)
Apr 22 22:44:01 www postfix/smtpd[24767]: resolve_clnt: `' ->
`warlordexample.com' -> transp=`local' host=`mail.example.com'
rcpt=`warlordexample.com' flags= class=local
Apr 22 22:44:01 www postfix/smtpd[24767]: ctable_locate: install entry
key warlordexample.com
Apr 22 22:44:01 www postfix/smtpd[24767]: extract_addr: in:
<warlordexample.com>, result: warlordexample.com
Apr 22 22:44:01 www postfix/smtpd[24767]: send attr request = rewrite
Apr 22 22:44:01 www postfix/smtpd[24767]: send attr rule = local
Apr 22 22:44:01 www postfix/smtpd[24767]: send attr address = postmaster
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: flags
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: flags
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value: 0
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: address
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: address
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value:
postmasterexample.com
Apr 22 22:44:01 www postfix/smtpd[24767]: private/rewrite socket: wanted
attribute: (list terminator)
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: (end)
Apr 22 22:44:01 www postfix/smtpd[24767]: rewrite_clnt: local:
postmaster -> postmasterexample.com
Apr 22 22:44:01 www postfix/smtpd[24767]: >>> START Recipient address
RESTRICTIONS <<<
Apr 22 22:44:01 www postfix/smtpd[24767]: generic_checks:
name=permit_mynetworks
Apr 22 22:44:01 www postfix/smtpd[24767]: permit_mynetworks: unknown
127.0.0.1
Apr 22 22:44:01 www postfix/smtpd[24767]: match_hostname: unknown ~?
127.0.0.0/8
Apr 22 22:44:01 www postfix/smtpd[24767]: match_hostaddr: 127.0.0.1 ~?
127.0.0.0/8
Apr 22 22:44:01 www postfix/smtpd[24767]: generic_checks:
name=permit_mynetworks status=1
Apr 22 22:44:01 www postfix/smtpd[24767]: before input_transp_cleanup:
cleanup flags = enable_header_body_filter enable_automatic_bcc
enable_address_mapping enable_milters
Apr 22 22:44:01 www postfix/smtpd[24767]: after input_transp_cleanup:
cleanup flags = enable_automatic_bcc enable_address_mapping
Apr 22 22:44:01 www postfix/smtpd[24767]: connect to subsystem
public/cleanup
Apr 22 22:44:01 www postfix/smtpd[24767]: public/cleanup socket: wanted
attribute: queue_id
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: queue_id
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value: 31E2158E
Apr 22 22:44:01 www postfix/smtpd[24767]: public/cleanup socket: wanted
attribute: (list terminator)
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: (end)
Apr 22 22:44:01 www postfix/smtpd[24767]: send attr flags = 48
Apr 22 22:44:01 www postfix/smtpd[24767]: 31E2158E:
client=unknown[127.0.0.1]
Apr 22 22:44:01 www postfix/smtpd[24767]: > unknown[127.0.0.1]: 250 2.1.5 Ok
Apr 22 22:44:01 www postfix/smtpd[24767]: < unknown[127.0.0.1]: DATA
Apr 22 22:44:01 www postfix/smtpd[24767]: > unknown[127.0.0.1]: 354 End
data with <CR><LF>.<CR><LF>
Apr 22 22:44:01 www postfix/cleanup[24762]: 31E2158E:
message-id=<480E4DB6.5020005lesniakowie.com>
Apr 22 22:44:01 www postfix/smtpd[24767]: public/cleanup socket: wanted
attribute: status
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: status
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value: 0
Apr 22 22:44:01 www postfix/smtpd[24767]: public/cleanup socket: wanted
attribute: reason
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: reason
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute value: (end)
Apr 22 22:44:01 www postfix/smtpd[24767]: public/cleanup socket: wanted
attribute: (list terminator)
Apr 22 22:44:01 www postfix/qmgr[24743]: 31E2158E:
from=<warlordlesniakowie.com>, size=1828, nrcpt=1 (queue active)
Apr 22 22:44:01 www postfix/smtpd[24767]: input attribute name: (end)
Apr 22 22:44:01 www postfix/smtpd[24767]: > unknown[127.0.0.1]: 250
2.0.0 Ok: queued as 31E2158E
Apr 22 22:44:01 www postfix/smtpd[24767]: < unknown[127.0.0.1]: QUIT
Apr 22 22:44:01 www postfix/smtpd[24767]: > unknown[127.0.0.1]: 221
2.0.0 Bye
Apr 22 22:44:01 www postfix/smtpd[24767]: match_hostname: unknown ~?
127.0.0.0/8
Apr 22 22:44:01 www postfix/smtpd[24767]: match_hostaddr: 127.0.0.1 ~?
127.0.0.0/8
Apr 22 22:44:01 www postfix/smtpd[24767]: disconnect from unknown[127.0.0.1]
Apr 22 22:44:01 www amavis[24525]: (24525-01) Passed CLEAN,
[150.254.201.18] [85.221.131.105] <warlordlesniakowie.com> ->
<warlordexample.com>, Message-ID: <480E4DB6.5020005lesniakowie.com>,
mail_id: KumjBLQdpBg2, Hits: -0.739, size: 1233, queued_as: 31E2158E,
1648 ms
Apr 22 22:44:01 www postfix/smtp[24763]: < 127.0.0.1[127.0.0.1]: 250
2.0.0 Ok: queued as 31E2158E
Apr 22 22:44:01 www postfix/smtp[24763]: 83C8B288:
to=<warlordexample.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=1.8,
delays=0.1/0/0/1.6, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as
31E2158E)
Apr 22 22:44:01 www postfix/smtp[24763]: name_mask: resource
Apr 22 22:44:01 www postfix/smtp[24763]: name_mask: software
Apr 22 22:44:01 www postfix/qmgr[24743]: 83C8B288: removed
Apr 22 22:44:01 www postfix/local[24768]: 31E2158E:
to=<warlordexample.com>, relay=local, delay=0.03,
delays=0.01/0.01/0/0.01, dsn=2.0.0, status=sent (delivered to command:
/usr/bin/procmail -f- -a "$USER")
Apr 22 22:44:01 www postfix/qmgr[24743]: 31E2158E: removed

On 2nd server it looks very similar, main difference is that one can see
postgrey in action:
Apr 23 20:03:32 mail amavis[5668]: (05668-05) load: 2 %, total idle
669.656 s, busy 13.089 s
Apr 23 20:03:32 mail postgrey[19117]: action=pass, reason=triplet found,
delay=1489, client_name=out01.wanadoo.es, client_address=62.36.20.201,
recipient=cora.villaztworking.com
Apr 23 20:03:33 mail postfix/policy-spf[5929]: handler
sender_policy_framework: is decisive.
Apr 23 20:03:33 mail postfix/policy-spf[5929]: : Policy action=PREPEND
Received-SPF: none (out01.wanadoo.es: No applicable sender policy
available) receiver=mail.working.com; identity=helo;
helo=out01.wanadoo.es; client-ip=62.36.20.201
Apr 23 20:03:33 mail postfix/smtpd[5503]: NOQUEUE: reject: RCPT from
out01.wanadoo.es[62.36.20.201]: 550 5.1.1 <cora.villaztworking.com>:
Recipient address rejected: User unknown in local recipient table;
from=<> to=<cora.villaztworking.com> proto=ESMTP helo=<out01.wanadoo.es>

I'm now concerned what is the cause of this difference.

I'll mention it once again, when I switch OKs to DUNNOs in
restricted_recipients.map on not working server, greylisting and spf
checks are being done. But with OKs, on working server greylisting (and
spf checking) takes place. Isn't this weird?

Pawel Lesniak

• Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]