通過使用 shell 命令可以很方便地對日誌進行統計和分析,當服務有異常的時候,需要去排查日誌,那麼掌握一種統計日誌的技巧就是必不可少的了。
假設有一個包含下面內容的日誌檔案 access.log
。我們以統計這個檔案的日誌為例。
date=2017-09-23 13:32:50 | ip=40.80.31.153 | method=GET | url=/api/foo/bar?params=something | status=200 | time=9.703 | bytes=129 | referrer="-" | user-agent="Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.7 (KHTML, like Gecko) Chrome/16.0.912.63 Safari/535.7" | cookie="-"
date=2017-09-23 00:00:00 | ip=100.109.222.3 | method=HEAD | url=/api/foo/healthcheck | status=200 | time=0.337 | bytes=10 | referrer="-" | user-agent="-" | cookie="-"
date=2017-09-23 13:32:50 | ip=40.80.31.153 | method=GET | url=/api/foo/bar?params=anything | status=200 | time=8.829 | bytes=466 | referrer="-" | user-agent="GuzzleHttp/6.2.0 curl/7.19.7 PHP/7.0.15" | cookie="-"
date=2017-09-23 13:32:50 | ip=40.80.31.153 | method=GET | url=/api/foo/bar?params=everything | status=200 | time=9.962 | bytes=129 | referrer="-" | user-agent="Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.7 (KHTML, like Gecko) Chrome/16.0.912.63 Safari/535.7" | cookie="-"
date=2017-09-23 13:32:50 | ip=40.80.31.153 | method=GET | url=/api/foo/bar?params=nothing | status=200 | time=11.822 | bytes=121 | referrer="-" | user-agent="Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.7 (KHTML, like Gecko) Chrome/16.0.912.63 Safari/535.7" | cookie="-"
不同的服務對應的日誌可能不一樣,本文使用示例日誌的格式是:
date | ip | method | url | status | time | bytes | referrer | user-agent | cookie
注意 mac 系統和 linux 系統中的命令列為可能不同,以下命令請在 linux 系統中使用
排除特殊日誌
統計日誌時,我們可能不關心 HEAD 請求,或者只關心 GET 請求,這裡首先需要篩選日誌,可以使用 grep
命令。-v
的含義是排除匹配的文字行。
grep GET access.log # 只統計 GET 請求
grep -v HEAD access.log # 不統計 HEAD 請求
grep -v `HEAD|POST` access.log # 不統計 HEAD 和 POST 請求
檢視介面耗時情況
我們可以將每行的 time
匹配出來,然後做一個排序。使用 awk 的 match
方法可以匹配正則:
awk `{ match($0, /time=([0-9]+.[0-9]+)/, result); print result[1]}` access.log
awk 命令使用方法如下:
awk `{pattern + action}` {filenames}
我們實際上只用到了 action:match($0, /time=([0-9]+.[0-9]+)/, result); print result[1]
這一段。
match
方法接收三個引數:需要匹配的文字、正規表示式、結果陣列。$0
代表 awk 命令處理的每一行,結果陣列是可選的,因為我們要拿到匹配結果所以這裡傳入了一個 result 陣列,用來儲存匹配後的結果。
注意這裡的正則我沒有使用 d
來表示數字,因為 awk 指令預設使用 “EREs”,不支援 d
的表示,具體請看 linux shell 正規表示式(BREs,EREs,PREs)差異比較。
result 陣列實際上和 javascript 裡的結果陣列很像了,所以我們列印出第二個元素,即匹配到的內容。執行完這行命令後結果如下:
9.703
0.337
8.829
9.962
11.822
當然實際上一天的日誌可能是成千上萬條,我們需要對日誌進行排序,且只展示前 3 條。這裡使用到 sort
命令。
sort
命令預設從小到大排序,且當作字串排序。所以預設情況下使用 sort 命令之後 "11"
會排在 "8"
前面。那麼需要使用 -n
指定按數字排序,-r
來按從大到小排序,然後我們檢視前 3 條:
awk `{ match($0, /time=([0-9]+.[0-9]+)/, result); print result[1]}` access.log | sort -rn | head -3
結果:
11.822
9.962
9.703
檢視耗時最高的介面
當然我們一般不會只檢視介面耗時情況,還需要把具體日誌也列印出來,上面的命令就不能滿足要求了。
awk 的列印預設是按空格分隔的,意思是 2017-09-23 GET
這一行如果使用 awk `{print $1}`
會列印出 "2017-09-23"
,類似地,$2
會列印出 GET
。
根據日誌特徵,我們可以使用 |
來作為分隔符,這樣就能列印出各個我們感興趣的值了。因為我們想找出耗時最高的介面,那麼我們把 time、date 和 url 單獨找出來。
awk 的 -F
引數用來自定義分隔符。然後我們可以數一下三個部分按 |
分隔後分別是第幾個:time 是第 6 個、date 是第 1 個、url 是第 4 個。
awk -F `|` `{print $6 $1 $4}` access.log
這樣打出來結果為:
time=9.703 date=2017-09-23 13:32:50 url=/api/foo/bar?params=something
time=0.337 date=2017-09-23 00:00:00 url=/api/foo/healthcheck
time=8.829 date=2017-09-23 13:32:50 url=/api/foo/bar?params=anything
time=9.962 date=2017-09-23 13:32:50 url=/api/foo/bar?params=everything
time=11.822 date=2017-09-23 13:32:50 url=/api/foo/bar?params=nothing
因為我們想按 time 來排序,而 sort 可以按列來排序,而列是按空格分隔的,我們目前第一列是 time=xxx
,是不能排序的,所以這裡要想辦法把 time=
給去掉,因為我們很雞賊地把耗時放在了第一列,那麼其實再通過 time=
進行分隔一下就行了。
awk -F `|` `{print $6 $1 $4}` access.log | awk -F `time=` `{print $2}`
結果:
9.703 date=2017-09-23 13:32:50 url=/api/foo/bar?params=something
0.337 date=2017-09-23 00:00:00 url=/api/foo/healthcheck
8.829 date=2017-09-23 13:32:50 url=/api/foo/bar?params=anything
9.962 date=2017-09-23 13:32:50 url=/api/foo/bar?params=everything
11.822 date=2017-09-23 13:32:50 url=/api/foo/bar?params=nothing
使用 sort
的 -k
引數可以指定要排序的列,這裡是第 1 列;再結合上面的排序,就能把耗時最高的日誌列印出來了:
awk -F `|` `{print $6 $1 $4}` access.log | awk -F `time=` `{print $2}` | sort -k1nr | head -3
結果:
11.822 date=2017-09-23 13:32:50 url=/api/foo/bar?params=nothing
9.962 date=2017-09-23 13:32:50 url=/api/foo/bar?params=everything
9.703 date=2017-09-23 13:32:50 url=/api/foo/bar?params=something
統計請求次數最多的介面
如果需要統計哪些介面每天請求量是最多的,只需要新引入 uniq
命令。
我們已經可以通過 grep -v HEAD access.log | awk -F `|` `{print $4}`
來篩選出所有的 url,uniq
命令可以刪除 相鄰 的相同的行,而 -c
可以輸出每行出現的次數。
所以我們先把 url 排序以讓相同的 url 放在一起,然後使用 uniq -c
來統計出現的次數:
grep -v HEAD access.log | awk -F `|` `{print $4}` | sort | uniq -c
因為示例日誌數量太少,我們假設日誌裡有多條,那麼結果應該類似下面:
1 url=/api/foo/bar?params=anything
19 url=/api/foo/bar?params=everything
4 url=/api/foo/bar?params=nothing
5 url=/api/foo/bar?params=something
接下來再 sort 即可:
grep -v HEAD access.log | awk -F `|` `{print $4}` | sort | uniq -c | sort -k1nr | head -10