[postfix-jp: 3522] Re: 特定の他ドメインからのメール受信が出来ない

[aihara@xxxxxxxxxx]

粟飯原です。

> 「上記ログの通り」と書かれていますが、ログには warning しか無く、
>「正常に配送されない」という部分のログが無いようにみえます。

正常に配送されないと言うのは少々語弊が有りました。
正確には、自サーバにはメールが不着であり当然ユーザーにも
メールは配送されておりません。

> 普通なら warnigの次に、
> 
> > postfix/smtpd[57912]: connect from unknown[210.xxx.xx.xxx]
> > postfix/smtpd[57912]: NOQUEUE: reject: RCPT from unknown[210.xxx.xx.
xxx]: 450 4.2.0 ...
> > postfix/smtpd[57912]: lost connection after DATA (0 bytes) from 
unknown[210.xxx.xx.xxx]
> > postfix/smtpd[57912]: disconnect from unknown[210.xxx.xx.xxx]
> 
> のような、ログがあるように思います。

確かに。
ですが普通であれば何かしらのログが出ていてもおかしくないのですが
maillogには先に投稿した内容通りのログしか吐き出さず
WARNINGでもメールが配送されていればスルーしている症状なのですが。。

> hostname がおかしいという warning が
> 出ているわけですから、xxxx.example.com 
> という名前ではなく 210.xxx.xx.xxxの IP アドレスでチェックするか
> その warning を出しているプロセスsmtpd[57912] でチェックして
> ログを呈示してみてはどうでしょうか。

debug_peer_listにてプロセスの詳細のログを確認してみたところ

Jun 28 09:14:54 centrum postfix/smtpd[70883]:
warning: 210.xxx.xx.xxx:hostname xxxx.example.com verification failed:
hostname nor servname provided, or not known
Jun 28 09:14:54 centrum postfix/smtpd[70883]:
connect from unknown[210.xxx.xx.xxx]
Jun 28 09:14:54 centrum postfix/smtpd[70883]:
match_hostname: unknown ~? 192.168.1.0/24
Jun 28 09:14:54 centrum postfix/smtpd[70883]:
match_hostaddr: 210.xxx.xx.xxx ~? 192.168.1.0/24
Jun 28 09:14:54 centrum postfix/smtpd[70883]:
match_hostname: unknown ~? 127.0.0.0/8
Jun 28 09:14:54 centrum postfix/smtpd[70883]:
match_hostaddr: 210.xxx.xx.xxx ~? 127.0.0.0/8
Jun 28 09:14:54 centrum postfix/smtpd[70883]:
match_list_match: unknown: no match
Jun 28 09:14:54 centrum postfix/smtpd[70883]:
match_list_match: 210.xxx.xx.xxx: no match
Jun 28 09:14:54 centrum postfix/smtpd[70883]:
auto_clnt_open: connected to private/anvil

**中略**
気になる部分がありましたので中略してその部分を記載します
以下のログで途中が切れているのは私が切ったのではなく
ログそのものが途中で切れております。

Jun 28 09:14:54 example postfix/smtpd[70883]: input attribute name: (end)
Jun 28 09:14:54 example postfix/smtpd[70883]: send attr flags = 178
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type T len 17 data 1246148094
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type A len 22 data rewrite_co
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type S len 24 data sa_owner@p
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type A len 23 data log_client
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type A len 33 data log_client
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type A len 21 data log_client
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type A len 42 data log_messag
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type A len 34 data log_helo_n
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type A len 23 data log_protoc
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type A len 19 data client_nam
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type A len 40 data reverse_cl
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type A len 29 data client_add
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type A len 17 data client_por
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type A len 30 data helo_name=
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type A len 19 data protocol_n
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type A len 21 data client_add
Jun 28 09:14:54 example postfix/smtpd[70883]:
699741CC45: client=unknown[210.xxx.xx.xxx]
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type A len 39 data dsn_orig_r
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type R len 18 data info@gangp
Jun 28 09:14:54 example postfix/smtpd[70883]:
vstream_fflush_some: fd 16 flush 518
Jun 28 09:14:54 example postfix/smtpd[70883]:> unknown
[210.xxx.xx.xxx]: 250 2.1.5 Ok
Jun 28 09:14:54 example postfix/smtpd[70883]:
watchdog_pat: 0x285038c8
Jun 28 09:14:54 example postfix/smtpd[70883]:< unknown
[210.xxx.xx.xxx]: DATA
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type M len 0 data 
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type N len 62 data Received: 
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type N len 54 data ?by mail.c
Jun 28 09:14:54 example postfix/smtpd[70883]:
rec_put: type N len 64 data ?for <info
Jun 28 09:14:54 example postfix/smtpd[70883]: > unknown
[210.xxx.xx.xxx]: 354 End data with <CR><LF>.<CR><LF>
Jun 28 09:14:54 example postfix/smtpd[70883]:
vstream_fflush_some: fd 11 flush 51

Jun 28 09:19:51 example postfix/smtpd[70883]: > unknown
[210.xxx.xx.xxx]: 421 4.4.2 mail.example.jp Error: timeout exceeded
◆↑この部分でタイムアウトしてその後disconnectされています

5分間の無応答がなぜ発生するのかよく分かりません。

Jun 28 09:19:51 example postfix/smtpd[70883]:
vstream_fflush_some: fd 11 flush 51

> また、「正常に配送されない」の中身を書かれてはどうでしょうか。
> 例えば先方にはエラーメールが届くのでしょうか。エラーメールや
> 先方のメールサーバのログがあれば分かりやすいように思います。

相手方サーバへはエラーメールが届いているかどうかも不明です。
恐らくdisconnectの内容がエラーで届いているとは思いますが
いずれも未確認です。(企業の為確認のしようが有りません)

今の段階では、特定ドメインからだけユーザーにメールが届かないと言う
ピンポイントなトラブルのため、こちらのサーバの不具合と考えており
相手側へのコンタクトは取っておりません。

冒頭でも記載しましたが、正常に配送されないという書き方では
少々語弊がありますね。。すみません。

単純に、『メールが届かない』の方が分かりやすいでしょうか。

なんらかのエラーで自サーバと相手方サーバの間で
メールが正常通り受け渡しされていないという感じです。

粟飯原

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