|
本期要介紹的主題是以 mail server 管理者為主，如果你是一個郵件伺服器的管理者，不管你有沒有啟動過濾，常常被使用者問到的是有人寄信給我郤沒有收到或者有使用者問，我寄的信對方沒有收到
。這個時候，你就必須學會查看記錄檔，從記錄檔中了解一些狀況。
本期主題介紹的是：郵件伺服器--mail server log 分析
Sendmail 記錄檔分析
提要
身為一個系統管理者，了解所管理的機器發生了什麼事情是非常重要的。而分析記錄檔是最基本且必要的技能，從中我們可以得到許多有用的資訊，例如：今天接收了多少封信件？多少人嘗試登入卻失敗？（也許是個攻擊伺服器的徵兆）諸如此類的資訊。所以我們必須了解記錄檔能告訴我們什麼，並且嘗試去分析記錄檔，進而協助垃圾郵件 (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, class=0, nrcpts=1, msgid=,
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, class=0, nrcpts=3, msgid=,
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 排序用
|
郵件所送到的伺服器位址
|
|
傳送狀態
|
從 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, class=0, nrcpts=1, msgid=,
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, class=0, 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, class=0, 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, class=0, nrcpts=1, msgid=, 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)
可得知該封信件寄出成功
如果想要得到較完整豐富的分析，可以寫個 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)
參考資料
Sendmail
|
My%20Webs/test/img/sp.gif){kind=small}
Blackboard專欄(第四期)
