Sendmail のログレベルの変更とメールログの解析
sendmail-cf のインストール
[root@kabosu ~]# yum install sendmail-cf ======================================================================= Package Arch Version Repository Size ======================================================================= Installing: sendmail-cf noarch 8.14.4-8.el6 base 184 k Installing for dependencies: hesiod x86_64 3.1.0-19.el6 base 20 k procmail x86_64 3.22-25.1.el6 base 163 k sendmail x86_64 8.14.4-8.el6 base 717 k Transaction Summary ======================================================================= Install 4 Package(s) Complete!
(一部省略)
log level の変更
[root@kabosu /etc/mail]# diff -u _sendmail.mc.back sendmail.mc --- _sendmail.mc.back 2013-11-21 17:16:12.742837063 +0900 +++ sendmail.mc 2013-11-21 17:17:14.020837174 +0900 @@ -18,7 +18,7 @@ dnl # default logging level is 9, you might want to set it higher to dnl # debug the configuration dnl # -dnl define(`confLOG_LEVEL', `9')dnl +define(`confLOG_LEVEL', `30')dnl dnl # dnl # Uncomment and edit the following line if your outgoing mail needs to dnl # be sent out through an external mail server:
sendmail.fc に反映
[root@kabosu /etc/mail]# make -C /etc/mail make: ディレクトリ `/etc/mail' に入ります make: ディレクトリ `/etc/mail' から出ます
sendmail をリスタート
[root@kabosu /etc/mail]# /etc/init.d/sendmail restart sm-client を停止中: [ OK ] sendmail を停止中: [ OK ] sendmail を起動中: [ OK ] sm-client を起動中: [ OK ]
メール送信PGを実行します。
ログレベル変更前
Nov 21 16:41:44 kabosu postfix/pickup[22268]: 770BC7447: uid=0 from=<hoge@foofoo.com>
Nov 21 16:41:44 kabosu postfix/cleanup[22909]: 770BC7447: message-id=<20131121074144.770BC7447@kabosu.localdomain>
Nov 21 16:41:44 kabosu postfix/qmgr[1166]: 770BC7447: from=<hoge@foofoo.com>, size=306, nrcpt=1 (queue active)
Nov 21 16:41:44 kabosu postfix/smtp[22911]: 770BC7447: to=<yhoge@foofoo.com>, relay=mail.foofoo.com[XXX.XXX.XXX.XXX]:25, delay=0.25, delays=0.02/0/0.12/0.11, dsn=2.0.0, status=sent (250 ok 1385019931 qp 17251)
Nov 21 16:41:44 kabosu postfix/qmgr[1166]: 770BC7447: removed
ログレベル変更後
Nov 21 17:28:34 kabosu sendmail[23841]: rAL8SYBr023841: from=hoge@foofoo.com, size=82, class=0, nrcpts=1, msgid=<201311210828.rAL8SYBr023841@kabosu>, relay=root@localhost
Nov 21 17:28:34 kabosu postfix/smtpd[23816]: connect from localhost[127.0.0.1]
Nov 21 17:28:35 kabosu postfix/smtpd[23816]: 07EF87582: client=localhost[127.0.0.1]
Nov 21 17:28:35 kabosu postfix/cleanup[23819]: 07EF87582: message-id=<201311210828.rAL8SYBr023841@kabosu>
Nov 21 17:28:35 kabosu postfix/qmgr[1166]: 07EF87582: from=<hoge@foofoo.com>, size=500, nrcpt=1 (queue active)
Nov 21 17:28:35 kabosu sendmail[23841]: rAL8SYBr023841: to=yhoge@foofoo.com, ctladdr=hoge@foofoo.com (0/0), delay=00:00:01, xdelay=00:00:01, mailer=relay, pri=30082, relay=[127.0.0.1] [127.0.0.1], dsn=2.0.0, stat=Sent (Ok: queued as 07EF87582)
Nov 21 17:28:35 kabosu postfix/smtpd[23816]: disconnect from localhost[127.0.0.1]
Nov 21 17:28:35 kabosu postfix/smtp[23820]: 07EF87582: to=<yhoge@foofoo.com>, relay=mail.foofoo.com[XXX.XXX.XXX.XXX]:25, delay=0.39, delays=0.11/0.01/0.11/0.16, dsn=2.0.0, status=sent (250 ok 1385022742 qp 19350)
Nov 21 17:28:35 kabosu postfix/qmgr[1166]: 07EF87582: removed
あれ、ログレベルMAXの30にしても、大して変わらない。やり方がおかしい？？ こちら を確認したら make -C コマンド以外でも m4 コマンドで sendmail.cf ファイルを作れるらしいので、そちらを確認してみたら原因が分かりました。
[root@kabosu /etc/mail]# m4 /etc/mail/sendmail.mc > /etc/sendmail.cf
変更したファイルを /etc に配置する必要があったのに /etc/mail に置きっ放しなのが原因でした。ハマって時間取られましたが、やっぱり原因は内(自分)にあるなー、よく調べるべきだと再認識しました。
sendmail をリスタート
[root@kabosu /etc/mail]# /etc/init.d/sendmail restart
sm-client を停止中: [ OK ]
sendmail を停止中: [ OK ]
sendmail を起動中: [ OK ]
sm-client を起動中: [ OK ]
メール送信PGを実行します。
ログレベル変更後
Nov 22 10:17:13 kabosu sendmail[2813]: rAM1HDJu002813: from=hoge@foofoo.com, size=81, class=0, nrcpts=1, msgid=<201311220117.rAM1HDJu002813@kabosu>, relay=root@localhost
Nov 22 10:17:13 kabosu sendmail[2814]: NOQUEUE: connect from localhost [127.0.0.1]
Nov 22 10:17:13 kabosu sendmail[2814]: AUTH: available mech=ANONYMOUS, allowed mech=EXTERNAL GSSAPI KERBEROS_V4 DIGEST-MD5 CRAM-MD5
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: Milter: no active filter
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: --- 220 kabosu ESMTP Sendmail 8.14.4/8.14.4; Fri, 22 Nov 2013 10:17:13 +0900
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: <-- EHLO kabosu
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: --- 250-kabosu Hello localhost [127.0.0.1], pleased to meet you
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: --- 250-ENHANCEDSTATUSCODES
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: --- 250-PIPELINING
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: --- 250-8BITMIME
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: --- 250-SIZE
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: --- 250-DSN
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: --- 250-ETRN
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: --- 250-DELIVERBY
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: --- 250 HELP
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: <-- MAIL From:<hoge@foofoo.com> SIZE=81
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: --- 250 2.1.0 <hoge@foofoo.com>... Sender ok
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: <-- RCPT To:<hoge@foofoo.com>
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: --- 250 2.1.5 <hoge@foofoo.com>... Recipient ok
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: <-- DATA
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: --- 354 Enter mail, end with "." on a line by itself
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: from=<hoge@foofoo.com>, size=313, class=0, nrcpts=1, msgid=<201311220117.rAM1HDJu002813@kabosu>, proto=ESMTP, daemon=MTA, relay=localhost [127.0.0.1]
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqn002814: --- 250 2.0.0 rAM1HDqn002814 Message accepted for delivery
Nov 22 10:17:13 kabosu sendmail[2813]: rAM1HDJu002813: to=hoge@foofoo.com, ctladdr=hoge@foofoo.com (0/0), delay=00:00:00, xdelay=00:00:00, mailer=relay, pri=30081, relay=[127.0.0.1] [127.0.0.1], dsn=2.0.0, stat=Sent (rAM1HDqn002814 Message accepted for delivery)
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqo002814: <-- QUIT
Nov 22 10:17:13 kabosu sendmail[2814]: rAM1HDqo002814: --- 221 2.0.0 kabosu closing connection
Nov 22 10:17:13 kabosu sendmail[2816]: rAM1HDqn002814: SMTP outgoing connect on lemon.interlink.local
Nov 22 10:17:13 kabosu sendmail[2816]: AUTH=client, relay=mail.foofoo.com., mech=, bits=0
Nov 22 10:17:13 kabosu sendmail[2816]: rAM1HDqn002814: to=<hoge@foofoo.com>, delay=00:00:00, xdelay=00:00:00, mailer=esmtp, pri=120313, relay=mail.foofoo.com. [XXX.XXX.XXX.XXX], dsn=2.0.0, stat=Sent (ok 1385083260 qp 17982)
Nov 22 10:17:13 kabosu sendmail[2816]: rAM1HDqn002814: done; delay=00:00:00, ntries=1
ログ出たー！！！ただ、この作業の狙いは、送信先アドレスが存在しない場合に、ログからその旨が分かるかどうかです。ログを解析メールが届かなくなってるユーザーに通知したい目的があったのですが残念ながら、送信先のメールアドレスが無効な場合と有効な場合でエラーログに差異がありませんでした。
ログレベル変更後(存在しないメールアドレス宛てに送信)
Nov 22 10:34:17 kabosu sendmail[3050]: rAM1YHj3003050: from=hoge@foofoo.com, size=82, class=0, nrcpts=1, msgid=<201311220134.rAM1YHj3003050@kabosu>, relay=root@localhost
Nov 22 10:34:17 kabosu sendmail[3051]: NOQUEUE: connect from localhost [127.0.0.1]
Nov 22 10:34:17 kabosu sendmail[3051]: AUTH: available mech=ANONYMOUS, allowed mech=EXTERNAL GSSAPI KERBEROS_V4 DIGEST-MD5 CRAM-MD5
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: Milter: no active filter
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: --- 220 kabosu ESMTP Sendmail 8.14.4/8.14.4; Fri, 22 Nov 2013 10:34:17 +0900
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: <-- EHLO kabosu
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: --- 250-kabosu Hello localhost [127.0.0.1], pleased to meet you
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: --- 250-ENHANCEDSTATUSCODES
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: --- 250-PIPELINING
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: --- 250-8BITMIME
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: --- 250-SIZE
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: --- 250-DSN
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: --- 250-ETRN
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: --- 250-DELIVERBY
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: --- 250 HELP
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: <-- MAIL From:<hoge@foofoo.com> SIZE=82
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: --- 250 2.1.0 <hoge@foofoo.com>... Sender ok
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: <-- RCPT To:<yhoge@foofoo.com>
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: --- 250 2.1.5 <yhoge@foofoo.com>... Recipient ok
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: <-- DATA
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: --- 354 Enter mail, end with "." on a line by itself
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: from=<hoge@foofoo.com>, size=315, class=0, nrcpts=1, msgid=<201311220134.rAM1YHj3003050@kabosu>, proto=ESMTP, daemon=MTA, relay=localhost [127.0.0.1]
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkU003051: --- 250 2.0.0 rAM1YHkU003051 Message accepted for delivery
Nov 22 10:34:17 kabosu sendmail[3050]: rAM1YHj3003050: to=yhoge@foofoo.com, ctladdr=hoge@foofoo.com (0/0), delay=00:00:00, xdelay=00:00:00, mailer=relay, pri=30082, relay=[127.0.0.1] [127.0.0.1], dsn=2.0.0, stat=Sent (rAM1YHkU003051 Message accepted for delivery)
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkV003051: <-- QUIT
Nov 22 10:34:17 kabosu sendmail[3051]: rAM1YHkV003051: --- 221 2.0.0 kabosu closing connection
Nov 22 10:34:17 kabosu sendmail[3053]: rAM1YHkU003051: SMTP outgoing connect on lemon.interlink.local
Nov 22 10:34:17 kabosu sendmail[3053]: AUTH=client, relay=mail.foofoo.com., mech=, bits=0
Nov 22 10:34:17 kabosu sendmail[3053]: rAM1YHkU003051: to=<yhoge@foofoo.com>, delay=00:00:00, xdelay=00:00:00, mailer=esmtp, pri=120315, relay=mail.foofoo.com. [XXX.XXX.XXX.XXX], dsn=2.0.0, stat=Sent (ok 1385084285 qp 18553)
Nov 22 10:34:17 kabosu sendmail[3053]: rAM1YHkU003051: done; delay=00:00:00, ntries=1
送信先のメールサーバーの MAILER-DEAMON から failure notice という件名で届いてないよ、という通知は来ています。自分のメールサーバーのアカウントが送信元の場合、結果が違ったかもしれませんが、今回はここまでです。
