このスレッドは解決済です(未解決に戻す場合はこちら)
<<戻る

Postfixでメールが届かないときの確認事項 このメッセージに返信する
日時: 2016/09/08(Thu) 10:12
名前: K
URL:
お世話になっております。
centos6です。
ずっと安定稼働させていましたが、8月28日にインド人?にサーバーを乗っ取られ、spamメールを送られてしまったので

1.乗っ取られたアカウントの削除
2.iptablesでTCP25、465、110、995、143、993をACCEPT_COUNTRYにして日本国内からしかアクセスできないように変更

の対策を取りました。
その後数日は普通にメールの授受ができていましたが、9月2日11:45のメールを最後にnagiosとCron Daemon、Anacronなど以外のメールが届いていないようです。

そこでメールの授受の確認事項を教えて頂けないでしょうか?

以下は一般プロバイダ(att.ne.jp)からメールを送信した時の各ログです。

/var/log/maillog
Sep 8 09:34:52 virtual postfix/smtpd[2128]: connect from msa506.att.ne.jp[210.134.90.16]
Sep 8 09:34:52 virtual postfix/smtpd[2128]: ABE1D41162: client=msa506.att.ne.jp[210.134.90.16]
Sep 8 09:34:52 virtual postfix/cleanup[2141]: ABE1D41162: message-id=<954D20968CB1AAFF482BFB4@kba.att.ne.jp>
Sep 8 09:34:52 virtual postfix/smtpd[2128]: disconnect from msa506.att.ne.jp[210.134.90.16]
Sep 8 09:34:52 virtual postfix/qmgr[1470]: ABE1D41162: from=<xxx@kba.att.ne.jp>, size=1213, nrcpt=1 (queue active)
Sep 8 09:34:53 virtual postfix/smtpd[2145]: connect from localhost[127.0.0.1]
Sep 8 09:34:53 virtual postfix/smtpd[2145]: 431A34194E: client=localhost[127.0.0.1]
Sep 8 09:34:53 virtual postfix/cleanup[2141]: 431A34194E: message-id=<954D20968CB1AAFF482BFB4@kba.att.ne.jp>
Sep 8 09:34:53 virtual postfix/qmgr[1470]: 431A34194E: from=<xxx@kba.att.ne.jp>, size=1684, nrcpt=1 (queue active)
Sep 8 09:34:53 virtual postfix/smtpd[2145]: disconnect from localhost[127.0.0.1]
Sep 8 09:34:53 virtual amavis[1396]: (01396-05) Passed CLEAN, [210.134.90.16] [(メールクライアントのIPアドレス)] <xxx@kba.att.ne.jp> -> <(受信メールアカウント@受信サーバー)>, Message-ID: <954D20968CB1AAFF482BFB4@kba.att.ne.jp>, mail_id: detqmNn20NgI, Hits: -, size: 1213, queued_as: 431A34194E, 472 ms
Sep 8 09:34:53 virtual postfix/smtp[2142]: ABE1D41162: to=<(受信メールアカウント@受信サーバー)>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.72, delays=0.17/0.07/0.08/0.4, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=01396-05, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 431A34194E)
Sep 8 09:34:53 virtual postfix/qmgr[1470]: ABE1D41162: removed
Sep 8 09:34:53 virtual spamd[1377]: spamd: connection from localhost [127.0.0.1] at port 56649
Sep 8 09:34:53 virtual spamd[1377]: spamd: setuid to (受信メールアカウント) succeeded
Sep 8 09:34:53 virtual spamd[1377]: spamd: processing message <954D20968CB1AAFF482BFB4@kba.att.ne.jp> for (受信メールアカウント):503
Sep 8 09:34:55 virtual spamd[1377]: spamd: clean message (-0.5/13.0) for (受信メールアカウント):503 in 2.0 seconds, 1828 bytes.
Sep 8 09:34:55 virtual spamd[1377]: spamd: result: . 0 - BODY_SINGLE_WORD,CONTENT_TYPE_PRESENT,FREEMAIL_FROM,ISO2022JP_BODY,ISO2022JP_CHARSET,RCVD_IN_DNSWL_NONE,RP_MATCHES_RCVD scantime=2.0,size=1828,user=(受信メールアカウント),uid=503,required_score=13.0,rhost=localhost,raddr=127.0.0.1,rport=56649,mid=<954D20968CB1AAFF482BFB4@kba.att.ne.jp>,autolearn=ham
Sep 8 09:34:55 virtual postfix/local[2146]: 431A34194E: to=<(受信メールアカウント@受信サーバー)>, relay=local, delay=2.3, delays=0.04/0.08/0/2.2, dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail)
Sep 8 09:34:55 virtual postfix/qmgr[1470]: 431A34194E: removed
Sep 8 09:34:55 virtual dovecot: pop3-login: Login: user=<(受信メールアカウント)>, method=PLAIN, rip=(メールクライアントのIPアドレス), lip=(サーバーのIPアドレス), mpid=2162, TLS
Sep 8 09:34:55 virtual spamd[1375]: prefork: child states: II
Sep 8 09:34:55 virtual dovecot: pop3((受信メールアカウント)): Disconnected: Logged out top=0/0, retr=0/0, del=1/65, size=293365

/var/log/messages
該当時間にLOGは無いです


メール送信時のログです

/var/log/maillog
Sep 8 09:50:55 virtual postfix/smtpd[2399]: connect from (接続回線名)[(メールクライアントのIPアドレス)]
Sep 8 09:50:55 virtual postfix/smtpd[2399]: D28E441162: client=(接続回線名)[(メールクライアントのIPアドレス)], sasl_method=PLAI
N, sasl_username=(送信メールアカウント@送信サーバー)
Sep 8 09:50:55 virtual postfix/cleanup[2402]: D28E441162: message-id=<955D2096B08F3DD901257CF@(送信サーバー)>
Sep 8 09:50:55 virtual postfix/qmgr[1470]: D28E441162: from=<(送信メールアカウント@送信サーバー)>, size=968, nrcpt=1 (queue active)
Sep 8 09:50:56 virtual postfix/smtpd[2406]: connect from localhost[127.0.0.1]
Sep 8 09:50:56 virtual postfix/smtpd[2406]: 638FB4194E: client=localhost[127.0.0.1]
Sep 8 09:50:56 virtual postfix/cleanup[2402]: 638FB4194E: message-id=<955D2096B08F3DD901257CF@(送信サーバー)>
Sep 8 09:50:56 virtual postfix/qmgr[1470]: 638FB4194E: from=<(送信メールアカウント@送信サーバー)>, size=1433, nrcpt=1 (queue active)
Sep 8 09:50:56 virtual postfix/smtpd[2406]: disconnect from localhost[127.0.0.1]
Sep 8 09:50:56 virtual amavis[1395]: (01395-06) Passed CLEAN, [(メールクライアントのIPアドレス)] [(メールクライアントのIPアドレス)] <(送信メールアカウント@送信サーバー)> -> <xxx@kba.att.ne.jp>, Message-ID: <955D2096B08F3DD901257CF@(送信サーバー)>, mail_id: ROvyHLbWL3MU, Hits: -, size: 968, queued_as: 638FB4194E, 427 ms
Sep 8 09:50:56 virtual postfix/smtp[2403]: D28E441162: to=<xxx@kba.att.ne.jp>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.68, delays=0.17/0.07/0.01/0.44, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=01395-06, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 638FB4194E)
Sep 8 09:50:56 virtual postfix/qmgr[1470]: D28E441162: removed
Sep 8 09:50:56 virtual postfix/smtpd[2399]: disconnect from (接続回線名)[(メールクライアントのIPアドレス)]
Sep 8 09:50:56 virtual postfix/smtp[2407]: 638FB4194E: to=<xxx@kba.att.ne.jp>, relay=mx.att.ne.jp[143.90.15.134]:25, delay=0.5, delays=0.04/0.04/0.08/0.34, dsn=2.0.0, status=sent (250 <57BAB73A0067E2D5> Mail accepted)
Sep 8 09:50:56 virtual postfix/qmgr[1470]: 638FB4194E: removed



メールの授受の流れを完全に追うにはどこを確認すればいいのでしょうか?(iptablesのログとか?)

よろしくお願いします。
記事編集 編集

Page: | 1 | 2 | 3 |

Re: Postfixでメールが届かないときの確認事項 このメッセージに返信する
日時: 2016/09/14(Wed) 09:15
名前: 通りすがり
URL:
>fail2banの再起動をcidr.txtのチェックに組み込めば良いのでは?

iptables.shが実行されたときにfail2banの設定もクリアされてしまうので
知らないうちにfail2banが無効化されていたとならないようにするためです。
どちらでもいいとおもいますが、deny_ipもいじる場合は
iptables.shの一番したにかいておいてもいいかもしれません。
記事編集 編集
Re: Postfixでメールが届かないときの確認事項 このメッセージに返信する
日時: 2016/09/14(Wed) 09:22
名前: K
URL:
>通りすがり様
>stranger様

ありがとうございます。
実はfail2banを入れ、nssを更新し、yumで全体アップデートやら、各種設定をいじくりまくっていたらサーバーが激重になりまして、コンソールログインすらできなくなりました。(Login time out after 60 secondsと出て、パスワードを入れることができません)
サーバーはHyper-V上に設置してあるのですが、元PCのリソースモニターを見ますと該当サーバーのHDDファイルにかなりの読み込みアクセスがあり、それが原因かと思いました。

そこで、1日前のHDDバックアップデータに戻して見たところ、起動等は正常になったのですが、メールの送受信が再度できなくなってしまいました。
ただし、これは前回の時も数日後には元に戻った感じだったのでしばらく様子を見ようと思っていたところ、一晩たったらまたサーバーが激重でログインができなくなっていました。
特に読み込みアクセスが激しいことからアンチウイルスが走ってるのかもしれません。
とりあえず現状では何ともできないのでもう少し様子を見てみます。
記事編集 編集
Re: Postfixでメールが届かないときの確認事項 このメッセージに返信する
日時: 2016/09/14(Wed) 12:12
名前: K
URL:
どうしようもないので再度強制停止後起動、すぐにSSHでログインしてps auxをしてみたところ、clamdがものすごいアクセスをしているようです。
そこで、spamassassinをアンインストール、/etc/postfix/main.cfのmailbox_command = /usr/bin/procmailをコメントアウト、clamaとclamav-dbをアンインストールしたところ、普通にアクセスできるようになりました。

が、メールがおかしいです。

/var/log/maillog
Sep 14 12:04:40 virtual postfix/qmgr[1411]: 529AB41ACF: from=<nagios@(ドメイン名)>, size=743, nrcpt=1 (queue active)
Sep 14 12:04:40 virtual postfix/qmgr[1411]: 2A6074199C: from=<bounce-000352167-00054354469444@fcgp84.asp.cuenote.jp>, size=10500, nrcpt=1 (queue active)
Sep 14 12:04:40 virtual postfix/qmgr[1411]: 2B6CF41977: from=<nagios@(ドメイン名)>, size=709, nrcpt=1 (queue active)
Sep 14 12:04:40 virtual postfix/qmgr[1411]: 1B67E4195B: from=<Coleen17@gmgdisticaret.com>, size=12977, nrcpt=1 (queue active)
Sep 14 12:04:40 virtual postfix/qmgr[1411]: 79F6B40FB3: from=<(ユーザー名)@(ドメイン名)>, size=988, nrcpt=1 (queue active)
Sep 14 12:04:40 virtual postfix/qmgr[1411]: 9778740FCD: from=<nagios@(ドメイン名)>, size=716, nrcpt=1 (queue active)
Sep 14 12:04:40 virtual postfix/smtp[2076]: connect to 127.0.0.1[127.0.0.1]:10024: Connection refused
Sep 14 12:04:40 virtual postfix/smtp[2076]: 529AB41ACF: to=<nagios@(ドメイン名)>, relay=none, delay=1007, delays=1007/0.02/0/0, dsn=4.4.1, status=deferred (connect to 127.0.0.1[127.0.0.1]:10024: Connection refused)
Sep 14 12:04:40 virtual postfix/smtp[2076]: connect to 127.0.0.1[127.0.0.1]:10024: Connection refused
Sep 14 12:04:40 virtual postfix/smtp[2077]: connect to 127.0.0.1[127.0.0.1]:10024: Connection refused
Sep 14 12:04:40 virtual postfix/smtp[2076]: 2A6074199C: to=<(ユーザー名)@(ドメイン名)>, relay=none, delay=307, delays=307/0.04/0.03/0, dsn=4.4.1, status=deferred (connect to 127.0.0.1[127.0.0.1]:10024: Connection refused)
Sep 14 12:04:40 virtual postfix/smtp[2076]: connect to 127.0.0.1[127.0.0.1]:10024: Connection refused
Sep 14 12:04:40 virtual postfix/smtp[2077]: 2B6CF41977: to=<nagios@(ドメイン名)>, relay=none, delay=314, delays=314/0.06/0.01/0, dsn=4.4.1, status=deferred (connect to 127.0.0.1[127.0.0.1]:10024: Connection refused)
Sep 14 12:04:40 virtual postfix/smtp[2076]: 1B67E4195B: to=<(ユーザー名)@(ドメイン名)>, relay=none, delay=332, delays=332/0.07/0.01/0, dsn=4.4.1, status=deferred (connect to 127.0.0.1[127.0.0.1]:10024: Connection refused)
Sep 14 12:04:40 virtual postfix/error[2070]: 79F6B40FB3: to=<(att.ne.jpのメールアドレス)>, relay=none, delay=578, delays=578/0.08/0/0.01, dsn=4.4.1, status=deferred (delivery temporarily suspended: connect to 127.0.0.1[127.0.0.1]:10024: Connection refused)
Sep 14 12:04:40 virtual postfix/error[2070]: 9778740FCD: to=<nagios@(ドメイン名)>, relay=none, delay=583, delays=583/0.09/0/0.01, dsn=4.4.1, status=deferred (delivery temporarily suspended: connect to 127.0.0.1[127.0.0.1]:10024: Connection refused)

という状況でConnection refusedが多数出ています。
postfix等をすべてアンイストールして、再度インストールしたほうがいいのでしょうか?
よろしくお願いいたします。
記事編集 編集
Re: Postfixでメールが届かないときの確認事項 このメッセージに返信する
日時: 2016/09/14(Wed) 15:56
名前: 通りすがり
URL:
なぜ対処方法が削除かインストールの選択になるのかがわからない。

なんか問題がある場合はサービスを止める。止まらない場合はkillコマンドを使うとか
そういう方法を取るべき。
その後、サーバーを調査した後設定変更などを行い
問題がなければサービスを再開させる。

また、confファイルいじる場合は必ずバックアップとっておく
問題が起きた場合はそのバックアップから復元したりする。


logみると10024: Connection refused)
amavisdをつかってるみたいだね。
clamdと連携していたんじゃないのかな?
それを削除してるから、おかしくなったかも
/etc/rc.d/init.d/amavisd stop
してmailを確認してみてください。
記事編集 編集
Re: Postfixでメールが届かないときの確認事項 このメッセージに返信する
日時: 2016/09/14(Wed) 17:54
名前: K
URL:
>通りすがり様

amavisdに関しては、既に削除されていました。
/etc/postfix/main.cf に content_filter=smtp-amavis:[127.0.0.1]:10024 の記載がありましたのでコメントアウトしたらメールの送信はできるようになりました。
ただし未だにメールの受信ができていません。

メール送信時のログ(送信できている)
Sep 14 17:40:19 virtual postfix/scache[9421]: statistics: start interval Sep 14 17:36:59
Sep 14 17:40:19 virtual postfix/scache[9421]: statistics: domain lookup hits=0 miss=1 success=0%
Sep 14 17:40:43 virtual postfix/smtpd[9477]: connect from 27-96-60-158.ipq.jp[27.96.60.158]
Sep 14 17:40:43 virtual postfix/smtpd[9477]: 9E58A41B32: client=27-96-60-158.ipq.jp[27.96.60.158], sasl_method=PLAIN, sasl_username=(ユーザー名)@virtual.(ドメイン名)
Sep 14 17:40:43 virtual postfix/cleanup[9480]: 9E58A41B32: message-id=<962D20E63B94B8A901257CF@(ドメイン名)>
Sep 14 17:40:43 virtual postfix/qmgr[9332]: 9E58A41B32: from=<(ユーザー名)@(ドメイン名)>, size=968, nrcpt=1 (queue active)
Sep 14 17:40:43 virtual postfix/smtp[9481]: 9E58A41B32: to=<(att.ne.jpのメールアドレス)>, relay=mx.att.ne.jp[143.90.15.134]:25, delay=0.25, delays=0.1/0.02/0.08/0.05, dsn=2.0.0, status=sent (250 <57C9154C0054B2DA> Mail accepted)
Sep 14 17:40:43 virtual postfix/qmgr[9332]: 9E58A41B32: removed
Sep 14 17:40:44 virtual postfix/smtpd[9477]: disconnect from 27-96-60-158.ipq.jp[27.96.60.158]

メール受信時のログ(受信できていない)
Sep 14 17:41:37 virtual postfix/smtpd[9504]: connect from msa504.att.ne.jp[210.134.90.14]
Sep 14 17:41:37 virtual postfix/smtpd[9504]: A98C241B33: client=msa504.att.ne.jp[210.134.90.14]
Sep 14 17:41:37 virtual postfix/cleanup[9480]: A98C241B33: message-id=<963D20E63D95B40F482BFB4@kba.att.ne.jp>
Sep 14 17:41:37 virtual postfix/qmgr[9332]: A98C241B33: from=<(att.ne.jpのメールアドレス)>, size=1772, nrcpt=1 (queue active)
Sep 14 17:41:37 virtual postfix/smtpd[9504]: disconnect from msa504.att.ne.jp[210.134.90.14]
Sep 14 17:41:37 virtual postfix/local[9509]: A98C241B33: to=<(ユーザー名)@(ドメイン名)>, relay=local, delay=0.13, delays=0.09/0.03/0/0.01, dsn=2.0.0, status=sent (delivered to maildir)
Sep 14 17:41:37 virtual postfix/qmgr[9332]: A98C241B33: removed

(delivered to maildir)の記載がありますので届いても良さそうなものなのですが・・・
サーバー内でメールがどのように流れているのでしょうか?(Maildirがmaildirと記載されているのが気になりますが関係ありませんか?)

よろしくお願いいたします。
記事編集 編集
Re: Postfixでメールが届かないときの確認事項 このメッセージに返信する
日時: 2016/09/15(Thu) 06:17
名前: 通りすがり
URL:
logみると正常に配信され
キューも削除されてる。
dovecot側になんかあるんじゃない?
記事編集 編集
Re: Postfixでメールが届かないときの確認事項 このメッセージに返信する
日時: 2016/09/15(Thu) 08:40
名前: stranger
URL: http://ja.528p.com/
Sep 14 17:41:37 virtual postfix/local[9509]: A98C241B33: to=<(ユーザー名)@(ドメイン名)>, relay=local, delay=0.13, delays=0.09/0.03/0/0.01, dsn=2.0.0, status=sent (delivered to maildir)

/home/(ユーザー名)に Maildir/cur Maildir/new Maildir/tmpは存在しますか
Maildir/newにファイルが存在しますか
存在すればたぶんそれが新規メールです
Maildir/newにたまったメールはメールクライアントからアクセスされ
読まれるとMaildir/curに移されます
その時にファイル名に :2,sbが付けられて既読メールになります

Maildir/newまではpostfixの役割で、それ以降はdovecotの役割になります

procmailも挟んでいるようなのでMaildir/newに届く前に
別の場所に振り分けられているってことはないの?
記事編集 編集
Re: Postfixでメールが届かないときの確認事項 このメッセージに返信する
日時: 2016/09/15(Thu) 08:54
名前: 通りすがり
URL:
>Maildir/newまではpostfixの役割で、それ以降はdovecotの役割になります

なるほど、流石strangerさん
勉強になります。
記事編集 編集
Re: Postfixでメールが届かないときの確認事項 このメッセージに返信する
日時: 2016/09/15(Thu) 09:08
名前: K
URL:
>通りすがり様
>stranger様

いつもありがとうございます。
Dovecotについては、ログファイルの作成設定がされていませんでしたので詳しいことがわからないのですが、/var/log/messageを見ますとかなり頻繁にsmtp-auth失敗が各国から来ているようです。
DROP_COUNTRYに入れているところははじいているようなので、漏れているところを追加しました。

また、ご指摘いただきましたメールを受け取ってからどのように振られていくのかの流れを教えて頂きましてありがとうございます。
どうやらサーバーを古いバックアップから戻すとしばらくこの流れがおかしくなるようですが、時間がたつとちゃんと動くようになるみたいです。
今朝、:2,sbが付くファイルまで確認し、送受信ができるようになっていました。

この現象について、どうにもこうにも原因がわからず困っていましたが、再度IOアクセスが高くなっていて調べたところMYSQLが高負荷をかけているようです。
それとiptables.shのDENY_COUNTRYの数を増やして bash -x iptables.sh をかけるとログアウトしてしまう(コンソールの場合はログアウト、SSHの場合は回線が切れる)という現象が発生したため、これ以上このサーバーを触るのは私には荷が勝ってしまうため、新しくサーバーを立て直すことにしました。

色々ご指導いただきまして、本当に感謝しております。
今後ともよろしくお願いいたします。
記事編集 編集
Re: Postfixでメールが届かないときの確認事項 このメッセージに返信する
日時: 2016/09/15(Thu) 09:20
名前: K
URL:
既に当初の質問からかけ離れていますが、一応ご報告です。
iptables.shのクラッシュについては、/var/log/messageにログが残っていまして、

Sep 15 08:43:30 virtual kernel: Out of memory: kill process 22203 (anvil) score 663 or a child
Sep 15 08:43:30 virtual kernel: Killed process 22203 (anvil) vsz:2652kB, anon-rss:0kB, file-rss:4kB
Sep 15 08:43:30 virtual kernel: Out of memory: kill process 22486 (iptables-restor) score 623 or a child
Sep 15 08:43:30 virtual kernel: Killed process 22486 (iptables-restor) vsz:39880kB, anon-rss:0kB, file-rss:4kB
Sep 15 08:44:15 virtual abrt[22526]: saved core dump of pid 22525 (/usr/libexec/fprintd) to /var/spool/abrt/ccpp-14
73896654-22525.new/coredump (655360 bytes)
Sep 15 08:44:15 virtual abrtd: Directory 'ccpp-1473896654-22525' creation detected
Sep 15 08:44:19 virtual abrtd: Crash is in database already (dup of /var/spool/abrt/ccpp-1473821383-1425)
Sep 15 08:44:19 virtual abrtd: Deleting crash ccpp-1473896654-22525 (dup of ccpp-1473821383-1425), sending dbus signal

ということで、どうもメモリ不足が原因のようでした。
その他の高負荷になる現象もスワップが原因かもしれません。
高負荷状態になるとタイムアウトになるのでそれが原因なのかも・・・

予想外のところに原因があったのかもしれません。

ということで、解決済みにさせて頂きます。
ありがとうございました。
記事編集 編集

Page: | 1 | 2 | 3 |

件名※必須
名前※必須
URL
任意のパスワード (投稿後のコメント修正・削除時に使用)
画像認証※必須 投稿キー(画像で表示されている数字を入力)
コメント※必須

※質問を投稿後に自己解決された場合は、原因と行った対処を具体的に書き込み下さるよう、よろしくお願いします。

- WEB PATIO -