Linux系統日誌分析的基本教程

 　　首先，我們將描述有關 Linux 日誌是什麼，到哪兒去找它們，以及它們是如何建立的基礎知識

　　Linux 系統日誌

　　許多有價值的記錄檔都是由 Linux 自動地為你建立的。你可以在 /var/log 目錄中找到它們。下面是在一個典型的 Ubuntu 系統中這個目錄的樣子：

　　一些最為重要的 Linux 系統日誌包括：

　　/var/log/syslog 或 /var/log/messages 儲存所有的全域系統活動資料，包括開機資訊。基於 Debian 的系統如 Ubuntu 在 /var/log/syslog 中儲存它們，而基於 RedHat 的系統如 RHEL 或 CentOS 則在 /var/log/messages 中儲存它們。

　　/var/log/auth.log 或 /var/log/secure 儲存來自可插拔認證模組(PAM)的日誌，包括成功的登入，失敗的登入嘗試和認證方式。Ubuntu 和 Debian 在 /var/log/auth.log 中儲存認證資訊，而 RedHat 和 CentOS 則在 /var/log/secure 中儲存該資訊。

　　/var/log/kern 儲存核心的錯誤和警告資料，這對於排除與定製核心相關的故障尤為實用。

　　/var/log/cron 儲存有關 cron 作業的資訊。使用這個資料來確保你的 cron 作業正成功地運行著。

　　Digital Ocean 有一個關於這些檔案的完整教程，介紹了 rsyslog 如何在常見的發行版本如 RedHat 和 CentOS 中建立它們。

　　應用程式也會在這個目錄中寫入記錄檔。例如像 Apache，Nginx，MySQL 等常見的伺服器程式可以在這個目錄中寫入記錄檔。其中一些記錄檔由應用程式自己建立，其他的則通過 syslog (具體見下文)來建立。

　　什麼是 Syslog?

　　Linux 系統記錄檔是如何建立的呢?答案是通過 syslog 精靈，它在 syslog 通訊端 /dev/log 上監聽日誌資訊，然後將它們寫入適當的記錄檔中。

　　單詞“syslog” 代表幾個意思，並經常被用來簡稱如下的幾個名稱之一：

　　Syslog 守護進程 — 一個用來接收、處理和發送 syslog 資訊的程式。它可以遠程發送 syslog 到一個集中式的伺服器或寫入到一個本地檔案。常見的例子包括 rsyslogd 和 syslog-ng。在這種使用方式中，人們常說“發送到 syslog”。

　　Syslog 協議 — 一個指定日誌如何通過網路來傳送的傳輸協議和一個針對 syslog 資訊(具體見下文) 的資料格式的定義。它在 RFC-5424 中被正式定義。對於文本日誌，標準的連接埠是 514，對於加密日誌，連接埠是 6514。在這種使用方式中，人們常說“通過 syslog 傳送”。

　　Syslog 資訊 — syslog 格式的日誌資訊或事件，它包括一個帶有幾個標準欄位的訊息頭。在這種使用方式中，人們常說“發送 syslog”。

　　Syslog 資訊或事件包括一個帶有幾個標準欄位的訊息頭，可以使分析和路由更方便。它們包括時間戳記、應用程式的名稱、在系統中資訊來源的分類或位置、以及事件的優先順序。

　　下面展示的是一個包含 syslog 訊息頭的日誌資訊，它來自於控制著到該系統的遠程登入的 sshd 守護進程，這個資訊描述的是一次失敗的登入嘗試：

　　<34>1 2003-10-11T22:14:15.003Z server1.com sshd - - pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=10.0.2.2

　　Syslog 格式和欄位

　　每條 syslog 資訊包含一個帶有欄位的資訊頭，這些欄位是結構化的資料，使得分析和路由事件更加容易。下面是我們使用的用來產生上面的 syslog 例子的格式，你可以將每個值匹配到一個特定的欄位的名稱上。

　　複製代碼

　　代碼如下:

　　<%pri%>%protocol-version% %timestamp:::date-rfc3339% %HOSTNAME% %app-name% %procid% %msgid% %msg%n

　　下面，你將看到一些在尋找或排錯時最常使用的 syslog 欄位：

　　時間戳記

　　時間戳記 (上面的例子為 2003-10-11T22:14:15.003Z) 暗示了在系統中發送該資訊的時間和日期。這個時間在另一系統上接收該資訊時可能會有所不同。上面例子中的時間戳記可以分解為：

　　2003-10-11 年，月，日。

　　T 為時間戳記的必需元素，它將日期和時間分隔開。

　　22:14:15.003 是 24 小時制的時間，包括進入下一秒的毫秒數(003)。

　　Z 是一個可選元素，指的是 UTC 時間，除了 Z，這個例子還可以包括一個位移量，例如 -08:00，這意味著時間從 UTC 位移 8 小時，即 PST 時間。

　　主機名稱

　　主機名稱 欄位(在上面的例子中對應 server1.com) 指的是主機的名稱或發送資訊的系統.

　　應用程式名稱

　　應用程式名稱 欄位(在上面的例子中對應 sshd:auth) 指的是發送資訊的程式的名稱.

　　優先順序

　　優先順序欄位或縮寫為 pri (在上面的例子中對應 ) 告訴我們這個事件有多緊急或多嚴峻。它由兩個數字欄位組成：設備欄位和緊急性欄位。緊急性欄位從代表 debug 類事件的數字 7 一直到代表緊急事件的數字 0 。設備欄位描述了哪個進程建立了該事件。它從代表核心資訊的數字 0 到代表本地應用使用的 23 。

　　Pri 有兩種輸出方式。第一種是以一個單獨的數字表示，可以這樣計算：先用設備欄位的值乘以 8，再加上緊急性欄位的值：(設備欄位)(8) + (緊急性欄位)。第二種是 pri 文本，將以“設備欄位.緊急性欄位” 的字串格式輸出。後一種格式更方便閱讀和搜尋，但佔據更多的儲存空間。

　　分析 Linux 日誌

　　日誌中有大量的資訊需要你處理，儘管有時候想要提取並非想象中的容易。在這篇文章中我們會介紹一些你現在就能做的基本日誌分析例子(只需要搜尋即可)。我們還將涉及一些更進階的分析，但這些需要你前期努力做出適當的設定，後期就能節省很多時間。對資料進行進階分析的例子包括產生匯總計數、對有效值進行過濾，等等。

　　我們首先會向你展示如何在命令列中使用多個不同的工具，然後展示了一個日誌管理工具如何能自動完成大部分繁重工作從而使得日誌分析變得簡單。

　　用 Grep 搜尋

　　搜尋文本是尋找資訊最基本的方式。搜尋文本最常用的工具是 grep。這個命令列工具在大部分 Linux 發行版中都有，它允許你用Regex搜尋日誌。Regex是一種用特殊的語言寫的、能識別匹配文本的模式。最簡單的模式就是用引號把你想要尋找的字串括起來。

　　Regex

　　這是一個在 Ubuntu 系統的認證日誌中尋找 “user hoover” 的例子：

　　複製代碼

　　代碼如下:

　　$ grep "user hoover" /var/log/auth.log

　　Accepted password for hoover from 10.0.2.2 port 4792 ssh2

　　pam_unix(sshd:session): session opened for user hoover by (uid=0)

　　pam_unix(sshd:session): session closed for user hoover

　　構建精確的Regex可能很難。例如，如果我們想要搜尋一個類似連接埠 “4792” 的數字，它可能也會匹配時間戳記、URL 以及其它不需要的資料。Ubuntu 中下面的例子，它匹配了一個我們不想要的 Apache 日誌。

　　複製代碼

　　代碼如下:

　　$ grep "4792" /var/log/auth.log

　　Accepted password for hoover from 10.0.2.2 port 4792 ssh2

　　74.91.21.46 - - [31/Mar/2015:19:44:32 +0000] "GET /scripts/samples/search?q=4972 HTTP/1.0" 404 545 "-" "-”

　　環繞搜尋

　　另一個有用的小技巧是你可以用 grep 做環繞搜尋。這會向你展示一個匹配前面或後面幾行是什麼。它能協助你調試導致錯誤或問題的東西。B 選項展示前面幾行，A 選項展示後面幾行。舉個例子，我們知道當一個人以管理員員身份登入失敗時，同時他們的 IP 也沒有反向解析，也就意味著他們可能沒有有效網域名稱。這非常可疑!

　　複製代碼

　　代碼如下:

　　$ grep -B 3 -A 2 'Invalid user' /var/log/auth.log

　　Apr 28 17:06:20 ip-172-31-11-241 sshd[12545]: reverse mapping checking getaddrinfo for 216-19-2-8.commspeed.net [216.19.2.8] failed - POSSIBLE BREAK-IN ATTEMPT!

　　Apr 28 17:06:20 ip-172-31-11-241 sshd[12545]: Received disconnect from 216.19.2.8: 11: Bye Bye [preauth]

　　Apr 28 17:06:20 ip-172-31-11-241 sshd[12547]: Invalid user admin from 216.19.2.8

　　Apr 28 17:06:20 ip-172-31-11-241 sshd[12547]: input_userauth_request: invalid user admin [preauth]

　　Apr 28 17:06:20 ip-172-31-11-241 sshd[12547]: Received disconnect from 216.19.2.8: 11: Bye Bye [preauth]

　　Tail

　　你也可以把 grep 和 tail 結合使用來擷取一個檔案的最後幾行，或者追蹤記錄檔並即時列印。這在你做互動式更改的時候非常有用，例如啟動伺服器或者測試代碼更改。

　　複製代碼

　　代碼如下:

　　$ tail -f /var/log/auth.log | grep 'Invalid user'

　　Apr 30 19:49:48 ip-172-31-11-241 sshd[6512]: Invalid user ubnt from 219.140.64.136

　　Apr 30 19:49:49 ip-172-31-11-241 sshd[6514]: Invalid user admin from 219.140.64.136

　　關於 grep 和Regex的詳細介紹並不在本指南的範圍，但 Ryan’s Tutorials 有更深入的介紹。

　　日誌管理系統有更高的效能和更強大的搜尋能力。它們通常會索引資料並進行並行查詢，因此你可以很快的在幾秒內就能搜尋 GB 或 TB 的日誌。相比之下，grep 就需要幾分鐘，在極端情況下可能甚至幾小時。日誌管理系統也使用類似 Lucene 的查詢語言，它提供更簡單的文法來檢索數字、域以及其它。

　　用 Cut、 AWK、 和 Grok 解析

　　Linux 提供了多個命令列工具用於文本解析和分析。當你想要快速解析少量資料時非常有用，但處理大量資料時可能需要很長時間。

　　Cut

　　cut 命令允許你從有分隔字元的日誌解析欄位。分隔字元是指能分開欄位或索引值對的等號或逗號等。

　　假設我們想從下面的日誌中解析出使用者：

　　複製代碼

　　代碼如下:

　　pam_unix(su:auth): authentication failure; logname=hoover uid=1000 euid=0 tty=/dev/pts/0 ruser=hoover rhost= user=root

　　我們可以像下面這樣用 cut 命令擷取用等號分割後的第八個欄位的文本。這是一個 Ubuntu 系統上的例子：

　　複製代碼

　　代碼如下:

　　$ grep "authentication failure" /var/log/auth.log | cut -d '=' -f 8

　　root

　　hoover

　　root

　　nagios

　　nagios

　　AWK

　　另外，你也可以使用 awk，它能提供更強大的解析欄位功能。它提供了一個指令碼語言，你可以過濾出幾乎任何不相干的東西。

　　例如，假設在 Ubuntu 系統中我們有下面的一行日誌，我們想要提取登入失敗的使用者名稱稱：

　　複製代碼

　　代碼如下:

　　Mar 24 08:28:18 ip-172-31-11-241 sshd[32701]: input_userauth_request: invalid user guest [preauth]

　　你可以像下面這樣使用 awk 命令。首先，用一個Regex /sshd.*invalid user/ 來匹配 sshd invalid user 行。然後用 { print $9 } 根據預設的分隔字元空格列印第九個欄位。這樣就輸出了使用者名稱。

　　複製代碼

　　代碼如下:

　　$ awk '/sshd.*invalid user/ { print $9 }' /var/log/auth.log

　　guest

　　admin

　　info

　　test

　　ubnt

　　你可以在 Awk 使用者指南 中閱讀更多關於如何使用Regex和輸出欄位的資訊。

　　日誌管理系統

　　日誌管理系統使得解析變得更加簡單，使使用者能快速的分析很多的記錄檔。他們能自動解析標準的日誌格式，比如常見的 Linux 日誌和 Web 伺服器日誌。這能節省很多時間，因為當處理系統問題的時候你不需要考慮自己寫解析邏輯。

　　下面是一個 sshd 日誌訊息的例子，解析出了每個 remoteHost 和 user。這是 Loggly 中的一張截圖，它是一個雲端式的日誌管理服務。

　　你也可以對非標準格式自訂解析。一個常用的工具是 Grok，它用一個常見Regex庫，可以解析原始文本為結構化 JSON。下面是一個 Grok 在 Logstash 中解析核心記錄檔的案例配置：

　　複製代碼

　　代碼如下:

　　filter{

　　grok {

　　match => {"message" => "%{CISCOTIMESTAMP:timestamp} %{HOST:host} %{WORD:program}%{NOTSPACE} %{NOTSPACE}%{NUMBER:duration}%{NOTSPACE} %{GREEDYDATA:kernel_logs}"

　　}

　　}

　　下圖是 Grok 解析後輸出的結果：

　　用 Rsyslog 和 AWK 過濾

　　過濾使得你能檢索一個特定的欄位值而不是進行全文檢索索引。這使你的日誌分析更加準確，因為它會忽略來自其它部分日誌資訊不需要的匹配。為了對一個欄位值進行搜尋，你首先需要解析日誌或者至少有對事件結構進行檢索的方式。

　　如何對應用進行過濾

　　通常，你可能只想看一個應用的日誌。如果你的應用把記錄都儲存到一個檔案中就會很容易。如果你需要在一個聚集或集中式日誌中過濾一個應用就會比較複雜。下面有幾種方法來實現：

　　用 rsyslog 守護進程解析和過濾日誌。下面的例子將 sshd 應用的日誌寫入一個名為 sshd-message 的檔案，然後丟棄事件以便它不會在其它地方重複出現。你可以將它添加到你的 rsyslog.conf 檔案中測試這個例子。

　　複製代碼

　　代碼如下:

　　:programname, isequal, “sshd” /var/log/sshd-messages

　　&~

　　用類似 awk 的命令列工具提取特定欄位的值，例如 sshd 使用者名稱。下面是 Ubuntu 系統中的一個例子。

　　複製代碼

　　代碼如下:

　　$ awk '/sshd.*invalid user/ { print $9 }' /var/log/auth.log

　　guest

　　admin

　　info

　　test

　　ubnt

　　用日誌管理系統自動解析日誌，然後在需要的應用程式名稱上點擊過濾。下面是在 Loggly 日誌管理服務中提取 syslog 域的截圖。我們對應用程式名稱 “sshd” 進行過濾，如維恩圖表徵圖所示。

　　如何過濾錯誤

　　一個人最希望看到日誌中的錯誤。不幸的是，預設的 syslog 配置不直接輸出錯誤的嚴重性，也就使得難以過濾它們。

　　這裡有兩個解決該問題的方法。首先，你可以修改你的 rsyslog 配置，在記錄檔中輸出錯誤的嚴重性，使得便於查看和檢索。在你的 rsyslog 配置中你可以用 pri-text 添加一個 模板，像下面這樣：

　　複製代碼

　　代碼如下:

　　"<%pri-text%> : %timegenerated%,%HOSTNAME%,%syslogtag%,%msg%n"

　　這個例子會按照下面的格式輸出。你可以看到該資訊中指示錯誤的 err。

　　複製代碼

　　代碼如下:

　　 : Mar 11 18:18:00,hoover-VirtualBox,su[5026]:, pam_authenticate: Authentication failure

　　你可以用 awk 或者 grep 檢索錯誤資訊。在 Ubuntu 中，對這個例子，我們可以用一些文法特徵，例如 . 和 >，它們只會匹配這個域。

　　複製代碼

　　代碼如下:

　　$ grep '.err>' /var/log/auth.log

　　 : Mar 11 18:18:00,hoover-VirtualBox,su[5026]:, pam_authenticate: Authentication failure

　　你的第二個選擇是使用日誌管理系統。好的日誌管理系統能自動解析 syslog 訊息並抽取錯誤域。它們也允許你用簡單的點擊過濾日誌訊息中的特定錯誤。

　　下面是 Loggly 中一個截圖，顯示了高亮錯誤嚴重性的 syslog 域，表示我們正在過濾錯誤：