提要
身為一個系統管理者，了解所管理的機器發生了什麼事情是非常重要的。而分析記錄檔是最基本且必要的技能，從中我們可以得到許多有用的資訊，例如：今天接收了多少封信件？多少人嘗試登入卻失敗？（也許是個攻擊伺服器的徵兆）諸如此類的資訊。所以我們必須了解記錄檔能告訴我們什麼，並且嘗試去分析記錄檔，進而協助垃圾郵件 (Spam) 的阻擋與防治。這份文件主旨在於協助一個 Sendmail 管理者如何去了解並分析 Sendmail 的記錄檔。
系統環境
平台：Solaris 9
Sendmail 版本：Sendmail 8.12.10
介紹
記錄檔格式
Sendmail 的記錄檔放置的位置是端看其編譯時期參數或是 sendmail.cf 的設定值，一般而言，也會依據所在平台不同而有所差異，通常可以在下面的位置找到它們：
Solaris : /var/adm/log/mail
Linux: /var/log/mail or /var/log/mail/mail
FreeBSD:/var/log/maillog
讓我們看個例子。我們可以從這樣的記錄中獲得什麼資訊呢？
Oct 11 00:08:30 shona sendmail[28560]: [ID 801593 mail.info] j2VG8UoI028560: from=, size=1310,, nrcpts=1, msgid=<20051011160826.3451.qmail@mail.fakeurl.net>, proto=SMTP, daemon=MTA, relay=mail.fakeurl.net [192.168.20.15]
Oct 11 00:08:31 shona sendmail[28521]: [ID 801593 mail.info] j2VG8Gv2028521: from=, size=7591,, nrcpts=3, msgid=<200510111608.j2VG8Gv2028521@wgf.com.tw>, proto=SMTP, daemon=MTA, relay=[172.16.4.41]
Oct 11 00:08:31 shona sendmail[28590]: [ID 801593 mail.info] j2VG8UoI028560: to=, delay=00:00:01, xdelay=00:00:00, mailer=relay, pri=121310, relay=[10.115.1.15] [10.115.1.15], dsn=2.0.0, stat=Sent (j2VG8RjQ013936 Message accepted for delivery)
Oct 11 00:08:31 shona sendmail[28592]: [ID 801593 mail.info] j2VG8Gv2028521: to=,, delay=00:00:12, xdelay=00:00:00, mailer=relay, pri=187591, relay=[10.115.1.15] [10.115.1.15], dsn=2.0.0, stat=Sent (j2VG8RL7013937 Message accepted for delivery)
一行標準的記錄檔需要包含：
1.日期 (Date)
以 “月 日” 為其格式，例如 “Oct 11″
2.時間 (Time)
以 “時:分:秒” 為其格式，例如 “00:08:30″
3.主機名稱 (Host Name)
以此處為例，主機名稱為 shona
4.Sendmail 執行時期的 Process ID
例如 28560, 28512 等等
5.記錄檔層級 (Log Level)
前面曾經說過，Sendmail 記錄檔的位置是依據設定所決定，同樣的我們也可以透過設定決定所需記錄的訊息詳細程度，在 Sendmail 中定義了幾種層級，分別如下
| 1 | Minimal logging. |
| 2 | Serious system failures and potential security problems. |
| 3 | Other serious failures, malformed addresses, transient forward/include errors, connection timeouts. |
| 4 | Minor failures, out of date alias databases, connection rejections via check_rulesets. |
| 5 | Message collection statistics. |
| 6 | Creation of error messages VRFY and EXPN commands. |
| 7 | Delivery failures (host or user unknown, etc). |
| 8 | Successful deliveries and alias database rebuilds. |
| 9 | Message being deferred (due to a host being down, etc). |
| 10 | Database expansion (alias, forward, and userdb lookups). |
| 11 | NIS errors and end of job processing. |
| 12 | Logs all SMTP connections. |
| 13 | Log bad user shells, files with improper permissions, and other questionable situations. |
| 14 | Logs refused connections. |
| 15 | Log all incoming and outgoing SMTP commands. |
| 20 | Logs attempts to run locked queue files. These are not errors, but can be useful to note if your queue appears to be clogged. |
| 30 | Lost locks (only if using lockf instead of flock) |
其餘還有 64 以上的值是保留給除錯所使用，一般而言是不會使用到他們。
而 Sendmail 的記錄訊息是透過 syslog 來決定要記錄哪些訊息，syslog 中定義了七個層級
| 0 | Emergency |
| 1 | Alert |
| 2 | Critical |
| 3 | Error |
| 4 | Warning |
| 5 | Notice |
| 6 | Info |
| 7 | Debug |
在 Sendmail 中預設的 Log Level 為 9 ，相當於 syslog 的 Info。
例如上面的記錄檔所屬層級都是 info，通常這樣的記錄都是正常且較為不重要的訊息。
6.訊息辨識碼 (Message-ID)
這是記錄檔中相當重要的一項。由於 mail log 是乏態 (Stateless) 的記錄檔，這意思是說，幾行連續的記錄中也許包含了好幾封信的訊息，而 Message-ID 就是用來分辨該筆記錄檔所記錄的是哪一封郵件，因而他也是唯一的標記，每封不同的郵件就會有不同的 Message-ID。
例如上面第一筆和第三筆訊息的 Message-ID 是 “j2VG8UoI028560″，我們可以由此得知他是同一封郵件的記錄。
基本上每行記錄檔都有上面六項必要的訊息，可以作為分析的基準條件
|
基本資訊
|
|||||
| Oct 11 | 00:08:30 | shona | sendmail[28560]: | [ID 801593 mail.info] | j2VG8UoI028560 |
|
日期
|
時間
|
主機名稱
|
Sendmail PID
|
紀錄層級
|
訊息識別碼
|
7.其他欄位
而信件由誰所發送？收件者是誰？傳送成功與否？須分析其他欄位才可得知。以上面第一行紀錄檔為例：
那要怎麼知道這封信是寄給誰呢？由於每封郵件都有他獨特的 Message-ID，在這個例子是 “j2VG8UoI028560″ ，透過 Message-ID 我們便可找到下一筆記錄
|
基本資訊
|
|||||
| Oct 11 | 00:08:31 | shona | sendmail[28560]: | [ID 801593 mail.info] | j2VG8UoI028560 |
|
日期
|
時間
|
主機名稱
|
Sendmail PID
|
紀錄層級
|
訊息識別碼
|
|
其他資訊
|
|||
| to= | delay=00:00:01 | xdelay=00:00:00 | mailer=relay |
|
收件者 email
|
從接收郵件到嘗試傳送出去所花的時間
|
嘗試傳送的總時間，通常代表了連線的速度
|
將傳送給收件者所透過的 mailer
|
| pri=121310 | relay=[10.115.1.15] [10.115.1.15] | dsn=2.0.0 | stat=Sent (j2VG8RjQ013936 Message accepted for delivery) |
|
郵件優先性，進到 queue 排序用
|
郵件所送到的伺服器位址
|
Enhanced Error Code，可參考 RFC 2034
|
傳送狀態
|
從 Stat 欄位得知這封信傳送成功了！
上面兩種訊息分別是 from （寄件者）和 to （收件者）的紀錄，結果是正常的送出，那麼郵件異常或者錯誤的訊息會怎麼樣呢？這部份也是我們須去特別注意地方，去探討為什麼會發生這樣的錯誤？這樣的錯誤訊息是否仍是屬於可接受程度的錯誤呢？底下是具有異常訊息的記錄：
Oct 11 00:08:23 shona sendmail[28528]: [ID 801593 mail.notice] j2VG8NKb028528:ruleset=CheckFrom, arg1=plato@fakeurl.net,relay=mail.fakeurl.net [192.168.20.15], reject=550 5.7.1 We don”t accept junk mail
Oct 11 00:08:25 shona sendmail[28528]: [ID 801593 mail.info] j2VG8NKb028528: from=, size=41096,, nrcpts=1, msgid=<200510111608.j2VG8NKb028528@realurl.net>, proto=ESMTP, daemon=MTA, relay=mail.fakeurl.net, [192.168.20.15]
Oct 11 00:08:25 shona sendmail[28528]: [ID 801593 mail.info] j2VG8NKb028528: to=, delay=00:00:02, pri=71096, stat=We don”t accept junk mail
Oct 11 00:08:31 shona sendmail[28524]: [ID 801593 mail.notice] j2VG8QDv028524:ruleset=check_mail, arg1=, relay=fakeurl.net [192.168.20.15] (may be forged), reject=451 4.5.1 Domain must resolve
Oct 11 00:08:31 shona sendmail[28524]: [ID 801593 mail.info] j2VG8QDv028524: from=, size=1665,, nrcpts=0, proto=ESMTP, daemon=MTA, relay=fakeurl.net [192.168.20.15] (may be forged)
除了前六項基本資訊一樣以外，異常的訊息跟正常的訊息有什麼差異呢？前面曾經提過記錄檔的訊息有分層級，在這裡可以看到 Notice 層級的訊息出現，而且正常訊息的 Message-ID 之後只有 from 和 to 兩種標籤，異常訊息則多出現了 “ruleset” 訊息行。這代表了什麼意思呢？是否該特別留意呢？
從 Sendmail 8.8 開始支援 check_* 的 ruleset，透過簡單的設置可以阻擋一些垃圾郵件，上面的訊息便是該封信件的寄件者被我們列入黑名單，所以會產生 ruleset=CheckFrom 的記錄，所以這樣的記錄我們可以將它視為正常訊息。
ruleset 的記錄可分為下列幾種欄位
|
其他資訊
|
|||
| ruleset=CheckFrom, | arg1=plato@fakeurl.net | relay=mail.fakeurl.net [192.168.20.15] | reject=550 5.7.1 We don”t accept junk mail |
| ruleset 規則集 | 收件者 | 寄件者主機 | 拒收理由 |
ruleset 規則集，Sendmail 預設支援下列四種規則，也可自訂規則集，如 CheckFrom 規則
| Check_mail | 檢驗寄件者 email address |
| Check_rcpt | 檢驗收件者 email address |
| Check_relay | 檢驗連線主機 |
| Check_compat | 檢驗寄件者和收件者 email address |
check_* 詳細的設定可以參考 Sendmail 官方說明或是我們的範例。
錯誤訊息會因 Sendmail compile 進去的功能而多出不同的錯誤訊息，我們無法列出所有的錯誤訊息，不過在分析的時候我們可以大致將訊息分成三個部份：
1.正常訊息：一般而言層級都是 info ，僅需要將其列入統計資料做數量的分析，避免阻斷式攻擊 (DOS)。
2.已知錯誤訊息：向上面的例子屬於 notice 層級的訊息，但是我們已知產生原因，也可將此類訊息當作正常訊息看待。
3.未知錯誤訊息：這類的訊息是我們較想了解的部份，通常層級高於 notice ，可能是 warning 或 critical，須將此類訊息特別另外記錄，觀察是否僅為單一事件，或為常發性的嚴重錯誤訊息，若是可接受範圍的錯誤訊息（例如某些郵件伺服器因連線速度過慢導致 timeout），我們可以將他視為已知錯誤訊息。下面是個嚴重錯誤訊息的例子：
Oct 11 00:08:23 shona sendmail[26212]: [ID 801593 mail.warning] j2VFvlmV026212: collect: premature EOM: Connection reset by [10.10.1.15]
Oct 11 00:08:23 shona sendmail[26212]: [ID 801593 mail.crit] j2VFvlmV026212: SYSERR(root): collect: I/O error on connection from [10.10.1.15], from=
Oct 11 00:08:23 shona sendmail[26212]: [ID 801593 mail.info] j2VFvlmV026212: from=, size=2850,, nrcpts=1, proto=ESMTP, daemon=MTA, relay=[10.10.1.15]
分析
綜合以上資訊，便可透過 Unix-like 常見的指令或是強大的 perl 來作進行 log 檔的分析。底下有幾個簡單的例子。
查詢伺服器收了幾封信件？
$ grep “from=” /var/log/mail | wc -l
查詢記錄檔中的某些日期的郵件數量，例如 Oct 11
$ grep “Oct 11″ /var/adm/mail | grep “from=”| wc -l
查詢某使用者的某封信件狀況
$ grep “dog@realurl.net” /var/log/mail
Oct 11 00:08:31 shona sendmail[28590]: [ID 801593 mail.info] j2VG8UoI028560: to=, delay=00:00:01, xdelay=00:00:00, mailer=relay, pri=121310, relay=[10.115.1.15] [10.115.1.15], dsn=2.0.0, stat=Sent (j2VG8RjQ013936 Message accepted for delivery
接著利用 Message-ID 做搜尋
$ grep “j2VG8UoI028560″ /var/log/mail
Oct 11 00:08:30 shona sendmail[28560]: [ID 801593 mail.info] j2VG8UoI028560: from=, size=1310,, nrcpts=1, msgid=<20051011160826.3451.qmail@mail.fakeurl.net>, proto=SMTP, daemon=MTA, relay=mail.fakeurl.net [192.168.20.15]
Oct 11 00:08:31 shona sendmail[28590]: [ID 801593 mail.info] j2VG8UoI028560: to=, delay=00:00:01, xdelay=00:00:00, mailer=relay, pri=121310, relay=[10.115.1.15] [10.115.1.15], dsn=2.0.0, stat=Sent (j2VG8RjQ013936 Message accepted for delivery)
可得知該封信件寄出成功r
如果想要得到較完整豐富的分析，可以寫個 perl 程式來作處理，網路上也許多免費軟體或收費商業軟體可使用。
免費軟體
SMA – Sendmail log analyzer (written in C, for Sendmail)
sendmail_stat (written in C, for Sendmail)
pflogsumm (written in perl, for Postfix)
eximstats (for exim)
商業軟體
Sawmill ( supports 600 different log formats)
參考資料
zz from: http://enews.cc.ncu.edu.tw/enews/post_view2.php?unit=1&sn=155
Leave a Reply