[postfix-jp: 2945] smtpd_recipient_restrictionsが飛ばされる事象。

[YAMAGUCHI Masanori <postfix-ml@xxxxxxxxxx>]

  初めまして。山口と申します。長いこと ML は参考にさせていただい
ておりましたが、初めて投稿いたします。
  自宅のサーバーで postfix を動かし、職場でも postfix を管理して
おります。

  自宅では、利用者が限られることもあり、かなり強硬な anti spam
設定で spam をほとんど受信しない環境を実現しています。
  職場でも、root 宛や postmaster 宛の spam が尋常ならざる数になっ
てきたので、自宅の設定を参考に anti spam の設定をしてみました。
大部分は意図したように reject するようになったのですが、一部すり
抜けて着信する spam があります。
  設定に漏れがあるのかと確認したのですが、原因が分からず、
master.cf で smtpd -v とやって冗長なログを取ったところ、
smtpd_recipient_restrictions の挙動がまったく行われずに、メッセー
ジ body の受信に入っているケースが見つかりました。
  この事例についてあれこれ探したのですが、見つけることができなかっ
たので、こちらで質問させていただく次第です。何かアドバイスがあり
ましたらよろしくお願いいたします。


●smtpd_recipient_restrictions が機能しなかった時のログ（実際に
受け取った spam です。自ドメインは example に置き換えています。）

Feb 19 04:17:14 mail postfix/smtpd[20311]: connect from unknown[222.254.109.247]
Feb 19 04:17:14 mail postfix/smtpd[20311]: match_list_match: unknown: no match
Feb 19 04:17:14 mail postfix/smtpd[20311]: match_list_match: 222.254.109.247: no match
（中略）
Feb 19 04:17:14 mail postfix/smtpd[20311]: > unknown[222.254.109.247]: 220 mail.example.com ESMTP Postfix
Feb 19 04:17:14 mail postfix/smtpd[20311]: < unknown[222.254.109.247]: EHLO 222.254.109.247
Feb 19 04:17:14 mail postfix/smtpd[20311]: > unknown[222.254.109.247]: 250-mail.example.com
Feb 19 04:17:14 mail postfix/smtpd[20311]: > unknown[222.254.109.247]: 250-PIPELINING
Feb 19 04:17:14 mail postfix/smtpd[20311]: > unknown[222.254.109.247]: 250-SIZE 4194304
Feb 19 04:17:14 mail postfix/smtpd[20311]: match_list_match: unknown: no match
Feb 19 04:17:14 mail postfix/smtpd[20311]: match_list_match: 222.254.109.247: no match
Feb 19 04:17:14 mail postfix/smtpd[20311]: > unknown[222.254.109.247]: 250-ETRN
Feb 19 04:17:14 mail postfix/smtpd[20311]: > unknown[222.254.109.247]: 250 8BITMIME
Feb 19 04:17:14 mail postfix/smtpd[20311]: < unknown[222.254.109.247]: MAIL From:<randal@xxxxxxxxxxxxx>
Feb 19 04:17:14 mail postfix/smtpd[20311]: extract_addr: input: <randal@xxxxxxxxxxxxx>
Feb 19 04:17:14 mail postfix/smtpd[20311]: smtpd_check_addr: addr=randal@xxxxxxxxxxxxx
（中略）
Feb 19 04:17:14 mail postfix/smtpd[20311]: > unknown[222.254.109.247]: 250 Ok
Feb 19 04:17:14 mail postfix/smtpd[20311]: < unknown[222.254.109.247]: RCPT To:<postmaster@example.com>
Feb 19 04:17:14 mail postfix/smtpd[20311]: extract_addr: input: <postmaster@example.com>
Feb 19 04:17:14 mail postfix/smtpd[20311]: smtpd_check_addr: addr=postmaster@example.com
Feb 19 04:17:14 mail postfix/smtpd[20311]: send attr request = rewrite
Feb 19 04:17:14 mail postfix/smtpd[20311]: send attr rule = local
Feb 19 04:17:14 mail postfix/smtpd[20311]: send attr address = postmaster@example.com
Feb 19 04:17:14 mail postfix/smtpd[20311]: private/rewrite socket: wanted attribute: flags
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute name: flags
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute value: 0
Feb 19 04:17:14 mail postfix/smtpd[20311]: private/rewrite socket: wanted attribute: address
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute name: address
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute value: postmaster@example.com
Feb 19 04:17:14 mail postfix/smtpd[20311]: private/rewrite socket: wanted attribute: (list terminator)
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute name: (end)
Feb 19 04:17:14 mail postfix/smtpd[20311]: rewrite_clnt: local: postmaster@example.com -> postmaster@example.com
Feb 19 04:17:14 mail postfix/smtpd[20311]: send attr request = resolve
Feb 19 04:17:14 mail postfix/smtpd[20311]: send attr address = postmaster@example.com
Feb 19 04:17:14 mail postfix/smtpd[20311]: private/rewrite socket: wanted attribute: flags
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute name: flags
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute value: 0
Feb 19 04:17:14 mail postfix/smtpd[20311]: private/rewrite socket: wanted attribute: transport
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute name: transport
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute value: local
Feb 19 04:17:14 mail postfix/smtpd[20311]: private/rewrite socket: wanted attribute: nexthop
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute name: nexthop
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute value: mail.example.com
Feb 19 04:17:14 mail postfix/smtpd[20311]: private/rewrite socket: wanted attribute: recipient
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute name: recipient
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute value: postmaster@example.com
Feb 19 04:17:14 mail postfix/smtpd[20311]: private/rewrite socket: wanted attribute: flags
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute name: flags
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute value: 256
Feb 19 04:17:14 mail postfix/smtpd[20311]: private/rewrite socket: wanted attribute: (list terminator)
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute name: (end)
Feb 19 04:17:14 mail postfix/smtpd[20311]: resolve_clnt: `postmaster@example.com' -> transp=`local' host=`mail.example.com' rcpt=`postmaster@example.com' flags= class=local
Feb 19 04:17:14 mail postfix/smtpd[20311]: ctable_locate: install entry key postmaster@example.com
Feb 19 04:17:14 mail postfix/smtpd[20311]: extract_addr: result: postmaster@example.com

■いつもなら、ここで >>> START Recipient address RESTRICTIONS <<< や
■ >>> CHECKING RECIPIENT MAPS <<< のログが出るのだが、全く出ない。

Feb 19 04:17:14 mail postfix/smtpd[20311]: smtpd_check_rewrite: trying: permit_inet_interfaces
Feb 19 04:17:14 mail postfix/smtpd[20311]: permit_inet_interfaces: unknown 222.254.109.247
Feb 19 04:17:14 mail postfix/smtpd[20311]: before input_transp_cleanup: cleanup flags = enable_header_body_filter enable_automatic_bcc enable_address_mapping
Feb 19 04:17:14 mail postfix/smtpd[20311]: after input_transp_cleanup: cleanup flags = enable_header_body_filter enable_automatic_bcc enable_address_mapping
Feb 19 04:17:14 mail postfix/smtpd[20311]: connect to subsystem public/cleanup
Feb 19 04:17:14 mail postfix/smtpd[20311]: public/cleanup socket: wanted attribute: queue_id
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute name: queue_id
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute value: 626B6221104
Feb 19 04:17:14 mail postfix/smtpd[20311]: public/cleanup socket: wanted attribute: (list terminator)
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute name: (end)
Feb 19 04:17:14 mail postfix/smtpd[20311]: send attr flags = 50
Feb 19 04:17:14 mail postfix/smtpd[20311]: 626B6221104: client=unknown[222.254.109.247]
Feb 19 04:17:14 mail postfix/smtpd[20311]: > unknown[222.254.109.247]: 250 Ok
Feb 19 04:17:14 mail postfix/smtpd[20311]: < unknown[222.254.109.247]: DATA
Feb 19 04:17:14 mail postfix/smtpd[20311]: > unknown[222.254.109.247]: 354 End data with <CR><LF>.<CR><LF>
Feb 19 04:17:14 mail postfix/smtpd[20311]: public/cleanup socket: wanted attribute: status
Feb 19 04:17:14 mail postfix/cleanup[20324]: 626B6221104: message-id=<000701c872e0$03ee30f8$659d4ea1@mlflxpfj>
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute name: status
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute value: 0
Feb 19 04:17:14 mail postfix/smtpd[20311]: public/cleanup socket: wanted attribute: reason
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute name: reason
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute value: (end)
Feb 19 04:17:14 mail postfix/smtpd[20311]: public/cleanup socket: wanted attribute: (list terminator)
Feb 19 04:17:14 mail postfix/smtpd[20311]: input attribute name: (end)
Feb 19 04:17:14 mail postfix/smtpd[20311]: > unknown[222.254.109.247]: 250 Ok: queued as 626B6221104
（後略）


●postconf の実行結果

[root@mail]# /usr/sbin/postconf mail_version
mail_version = 2.2.10
[root@mail]# /usr/sbin/postconf -n
alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
allow_mail_to_commands = alias,forward,include
command_directory = /usr/sbin
config_directory = /etc/postfix
daemon_directory = /usr/libexec/postfix
debug_peer_level = 2
disable_vrfy_command = yes
html_directory = no
mail_owner = postfix
mailbox_size_limit = 102400000
mailq_path = /usr/bin/mailq.postfix
manpage_directory = /usr/share/man
maps_rbl_reject_code = 454
masquerade_domains = example.com
message_size_limit = 4194304
mydestination = $myhostname, localhost.$mydomain, localhost, $mydomain
myhostname = mail.example.com
mynetworks = ***
myorigin = $mydomain
newaliases_path = /usr/bin/newaliases.postfix
queue_directory = /var/spool/postfix
readme_directory = /usr/share/doc/postfix-2.2.10/README_FILES
sample_directory = /usr/share/doc/postfix-2.2.10/samples
sendmail_path = /usr/sbin/sendmail.postfix
setgid_group = postdrop
smtpd_recipient_restrictions = permit_mynetworks        check_client_access hash:/etc/postfix/client    reject_unknown_sender_domain        reject_unauth_destination   check_sender_access hash:/etc/postfix/sender    check_recipient_access hash:/etc/postfix/rcpt_ok        check_client_access regexp:/etc/postfix/whitelist       reject_unknown_client   check_client_access regexp:/etc/postfix/rejections      reject_rbl_client all.rbl.jp        reject_rbl_client list.dsbl.org        reject_rbl_client sbl-xbl.spamhaus.org        reject_rbl_client bl.spamcop.net
smtpd_restriction_classes = permitted_only, anti_spam
soft_bounce = no
transport_maps = hash:/etc/postfix/transport
unknown_local_recipient_reject_code = 550
[root@mail]#

上記設定の補足：
  当初は、root や postmaster など、特定の宛先のメールのみ、クラ
イアントのチェックや RBL で reject するつもりでしたが、今回の問
題の切り分けのために、現在は全宛先についてチェックさせるようにし
ております。
# おかげでホワイトリストのメンテナンスが忙しい。:-)

-- 
YAMAGUCHI Masanori

_______________________________________________
Postfix-jp-list mailing list
Postfix-jp-list@xxxxxxxxxxxxxxxxxxxx
http://lists.sourceforge.jp/mailman/listinfo/postfix-jp-list