引言
我前幾天寫過的效能工具之linux三劍客awk、grep、sed詳解，我們已經詳細介紹 linux 三劍客的基本使用，接下來我們看看具體在效能測試領域的運用，本文主要介紹的是在 Tomcat 和 Nginx access日誌的統計分析。
Tomcat統計請求響應時間
server.xml 使用配置方式，%D-請求時間，%F響應時間
-
<Valve className="org.apache.catalina.valves.AccessLogValve" directory="logs" -
prefix="localhost_access_log." suffix=".txt" -
pattern="%h %l %u [%{yyyy-MM-dd HH:mm:ss}t] %{X-Real_IP}i "%r" %s %b %D %F" />
欄位說明如下：
-
%h- 發起請求的客戶端 IP 地址。這裡記錄的 IP 地址並不一定是真實使用者客戶機的 IP 地址，它可能是私網客戶端的公網對映地址或代理伺服器地址。 -
%l- 客戶機的 RFC 1413 標識 ( 參考 ) ，只有實現了 RFC 1413 規範的客戶端，才能提供此資訊。 -
%u- 遠端客戶端使用者名稱稱，用於記錄瀏覽者進行身份驗證時提供的名字，如登入百度的使用者名稱zuozewei，如果沒有登入就是空白。 -
%t- 收到請求的時間（訪問的時間與時區，比如18/Jul/2018:17:00:01+0800，時間資訊最後的"+0800"表示伺服器所處時區位於 UTC 之後的8小時） -
%{X-Real_IP}i- 客戶端的真實ip -
%r- 來自客戶端的請求行（請求的 URI 和 HTTP 協議，這是整個 PV 日誌記錄中最有用的資訊，記錄伺服器收到一個什麼樣的請求） -
%>s- 伺服器返回客戶端的狀態碼，比如成功是 200。 -
%b- 傳送給客戶端的檔案主體內容的大小，不包括響應頭的大小（可以將日誌每條記錄中的這個值累加起來以粗略估計伺服器吞吐量） -
%D- 處理請求的時間，以毫秒為單位 -
%F- 客戶端瀏覽器資訊提交響應的時間，以毫秒為單位
日誌樣例：
-
47.203.89.212 - - [19/Apr/2017:03:06:53 +0000] "GET / HTTP/1.1" 200 10599 50 49
Nginx統計請求和後臺服務響應時間
使用預設 combined 的經典格式上擴充套件 response_time&upstream_response_time
nginx.conf 使用配置方式：
-
log_format main '$remote_addr - $remote_user [$time_local] "$request" $status $body_bytes_sent $request_time $upstream_response_time "$http_referer" "$http_user_agent" "$http_x_forwarded_for"';
欄位說明如下：
-
$remote_addr- 發起請求的客戶端 IP 地址。這裡記錄的 IP 地址並不一定是真實使用者客戶機的 IP 地址，它可能是私網客戶端的公網對映地址或代理伺服器地址。 -
$remote_user- 遠端客戶端使用者名稱稱，用於記錄瀏覽者進行身份驗證時提供的名字，如登入百度的使用者名稱zuozewei，如果沒有登入就是空白。 -
[$time_local]- 收到請求的時間（訪問的時間與時區，比如18/Jul/2018:17:00:01+0800，時間資訊最後的"+0800"表示伺服器所處時區位於 UTC 之後的8小時） -
“$request”- 來自客戶端的請求行（請求的 URI 和 HTTP 協議，這是整個 PV 日誌記錄中最有用的資訊，記錄伺服器收到一個什麼樣的請求） -
$status- 伺服器返回客戶端的狀態碼，比如成功是 200。 -
$body_bytes_sent- 傳送給客戶端的檔案主體內容的大小，不包括響應頭的大小（可以將日誌每條記錄中的這個值累加起來以粗略估計伺服器吞吐量） -
$request_time- 整個請求的總時間，以秒為單位（包括接收客戶端請求資料的時間、後端程式響應的時間、傳送響應資料給客戶端的時間(不包含寫日誌的時間)） -
$upstream_response_time- 請求過程中，upstream 的響應時間,以秒為單位（向後端建立連線開始到接受完資料然後關閉連線為止的時間） -
“$http_referer”- 記錄從哪個頁面連結訪問過來的（請求頭 Referer 的內容 ） -
“$http_user_agent”- 客戶端瀏覽器資訊（請求頭User-Agent的內容 ） -
“$ http_x_forwarded_for”$remote_add拿到的IP地址是反向代理伺服器的iP地址。反向代理伺服器在轉發請求的 http 頭資訊中，可以增加x_forwarded_for** 資訊，用以記錄原有客戶端的IP地址和原來客戶端的請求的伺服器地址。
日誌示例：
-
218.56.42.148 - - [19/Apr/2017:01:58:04 +0000] "GET / HTTP/1.1" 200 0 0.023 - "-" "Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/57.0.2987.133 Safari/537.36" "-"
AWK 運用
為了能理解 AWK 程式，我們下面簡單概述其基本知識，詳細內容參照上文。
AWK 程式可以由一行或多行文字構成，其中核心部分是包含一個模式和動作的組合。
-
pattern { action }
模式( pattern ) 用於匹配輸入中的每行文字。對於匹配上的每行文字，awk 都執行對應的 動作( action )。模式和動作之間使用花括號隔開。awk 順序掃描每一行文字，並使用 記錄分隔符（一般是換行符）將讀到的每一行作為 記錄，使用 域分隔符( 一般是空格符或製表符 ) 將一行文字分割為多個 域， 每個域分別可以使用 $1, $2, … $n 表示。$1 表示第一個域，$2 表示第二個域，$n 表示第 n 個域。 $0 表示整個記錄。模式或動作都可以不指定，預設模式的情況下，將匹配所有行。預設動作的情況下，將執行動作 {print}，即列印整個記錄。
此處使用Nginx access.log 舉例，Tomcat 同學們自己舉一反三。
使用 awk 分解出Nginx access日誌中的資訊
-
218.56.42.148 - - [19/Apr/2017:01:58:04 +0000] "GET / HTTP/1.1" 200 0 0.023 - "-" "Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/57.0.2987.133 Safari/537.36" "-"
-
$0 就是整個記錄行
-
$1 就是訪問 IP
”218.56.42.148” -
$4 就是請求時間的前半部分
“[19/Apr/2017:01:58:04” -
$5 就是請求時間的後半部分
“+0000]”
以此類推……
當我們使用預設的域分割符時，我們可以從日誌中解析出下面不同型別的資訊：
-
awk '{print $1}' access.log # IP 地址 ($remote_addr) -
awk '{print $3}' access.log # 使用者名稱稱 $remote_user) -
awk '{print $4,$5}' access.log # 日期和時間 ([$time_local]) -
awk '{print $7}' access _log # URI ($request) -
awk '{print $9}' access _log # 狀態碼 ($status) -
awk '{print $10}' access _log # 響應大小 ($body_bytes_sent) -
awk '{print $11}' access _log # 請求時間 ($request_time) -
awk '{print $12}' access _log # upstream響應時間 ($upstream_response_time)
我們不難發現，僅使用預設的域分隔符，不方便解析出請求行、引用頁和瀏覽器型別等其他資訊，因為這些資訊之中包含不確定個數的空格。 因此，我們需要把域分隔符修改為 “ ，就能夠輕鬆讀出這些資訊。
-
awk -F\" '{print $2}' access.log # 請求行 ($request) -
awk -F\" '{print $4}' access.log # 引用頁 ($http_referer) -
awk -F\" '{print $6}' access.log # 瀏覽器 ($http_user_agent) -
awk -F\" '{print $8}' access.log # 真實ip ($http_x_forwarded_for)
注意：這裡為了避免 Linux Shell 誤解 “ 為字串開始，我們使用了反斜槓，轉義了 “ 。 現在，我們已經掌握了 awk 的基本知識，以及它是怎樣解析日誌的。
使用場景舉例
此處使用Nginx access.log 舉例，Tomcat 同學們自己舉一反三
瀏覽器型別統計
如果我們想知道那些型別的瀏覽器訪問過網站，並按出現的次數倒序排列，我可以使用下面的命令：
-
awk -F\" '{print $6}' access.log | sort | uniq -c | sort -fr
此命令列首先解析出瀏覽器域，然後使用管道將輸出作為第一個 sort 命令的輸入。第一個 sort 命令主要是為了方便 uniq 命令統計出不同瀏覽器出現的次數。最後一個 sort 命令將把之前的統計結果倒序排列並輸出。
發現系統存在的問題
我們可以使用下面的命令列，統計伺服器返回的狀態碼，發現系統可能存在的問題。
-
awk '{print $9}' access.log | sort | uniq -c | sort
正常情況下，狀態碼 200 或 30x 應該是出現次數最多的。40x 一般表示客戶端訪問問題。50x 一般表示伺服器端問題。 下面是一些常見的狀態碼：
-
200 - 請求已成功，請求所希望的響應頭或資料體將隨此響應返回。
-
206 - 伺服器已經成功處理了部分 GET 請求
-
301 - 被請求的資源已永久移動到新位置
-
302 - 請求的資源現在臨時從不同的 URI 響應請求
-
400 - 錯誤的請求。當前請求無法被伺服器理解
-
401 - 請求未授權，當前請求需要使用者驗證。
-
403 - 禁止訪問。伺服器已經理解請求，但是拒絕執行它。
-
404 - 檔案不存在，資源在伺服器上未被發現。
-
500 - 伺服器遇到了一個未曾預料的狀況，導致了它無法完成對請求的處理。
-
503 - 由於臨時的伺服器維護或者過載，伺服器當前無法處理請求。
HTTP 協議狀態碼定義可以參閱： https://www.w3.org/Protocols/rfc2616/rfc2616.html
狀態碼相關統計
查詢並顯示所有狀態碼為 404 的請求
-
awk '($9 ~ /404/)' access.log
統計所有狀態碼為 404 的請求
-
awk '($9 ~ /404/)' access.log | awk '{print $9,$7}' | sort
現在我們假設某個請求 ( 例如 : URI: /path/to/notfound ) 產生了大量的 404 錯誤，我們可以通過下面的命令找到這個請求是來自於哪一個引用頁，和來自於什麼瀏覽器。
-
awk -F\" '($2 ~ "^GET /path/to/notfound "){print $4,$6}' access.log
追查誰在盜鏈網站圖片
有時候會發現其他網站出於某種原因，在他們的網站上使用儲存在自己網站上的圖片。如果您想知道究竟是誰未經授權使用自己網站上的圖片，我們可以使用下面的命令：
-
awk -F\" '($2 ~ /\.(jpg|gif|png)/ && $4 !~ /^http:\/\/www\.example\.com/)\ -
{print $4}' access.log \ | sort | uniq -c | sort
注意：使用前，將 www.example.com 修改為自己網站的域名。
-
使用 ” 分解每一行；
-
請求行中必須包括 “.jpg” 、”.gif” 或 ”.png”；
-
引用頁不是以您的網站域名字串開始（ 在此例中，即 www.example.com ）；
-
顯示出所有引用頁，並統計出現的次數。
IP相關統計
統計共有多少個不同的 IP 訪問：
-
awk '{print $1}' access.log |sort|uniq|wc – l
統計每一個 IP 訪問了多少個頁面：
-
awk '{++S[$1]} END {for (a in S) print a,S[a]}' log_file
將每個 IP 訪問的頁面數進行從小到大排序：
-
awk '{++S[$1]} END {for (a in S) print S[a],a}' log_file | sort -n
統計 2018 年 8 月 31 日 14 時內有多少 IP 訪問 :
-
awk '{print $4,$1}' access.log | grep 31/Aug/2018:14 | awk '{print $2}'| sort | uniq | wc -l
統計訪問最多的前10個 IP 地址
-
awk '{print $1}' access.log |sort|uniq -c|sort -nr |head -10
列出某1個 IP訪問了哪些頁面：
-
grep ^202.106.19.100 access.log | awk '{print $1,$7}'
統計某個 IP 的詳細訪問情況,按訪問頻率排序
-
grep '202.106.19.100' access.log |awk '{print $7}'|sort |uniq -c |sort -rn |head -n 100
響應頁面大小相關統計
列出傳輸大小最大的幾個檔案
-
cat access.log |awk '{print $10 " " $1 " " $4 " " $7}'|sort -nr|head -100
列出輸出大於 204800 byte ( 200kb) 的頁面以及對應頁面發生次數
-
cat access.log |awk '($10 > 200000){print $7}'|sort -n|uniq -c|sort -nr|head -100
列出訪問最頻的頁面(TOP100)
-
awk '{print $7}' access.log | sort |uniq -c | sort -rn | head -n 100
列出訪問最頻的頁面([排除php頁面】(TOP100)
-
grep -v ".php" access.log | awk '{print $7}' | sort |uniq -c | sort -rn | head -n 100
列出頁面訪問次數超過100次的頁面
-
cat access.log | cut -d ' ' -f 7 | sort |uniq -c | awk '{if ($1 > 100) print $0}' | less
列出最近1000條記錄，訪問量最高的頁面
-
tail -1000 access.log |awk '{print $7}'|sort|uniq -c|sort -nr|less
PV 相關統計
統計每分鐘的請求數,top100的時間點(精確到分鐘)
-
awk '{print $4}' access.log |cut -c 14-18|sort|uniq -c|sort -nr|head -n 100
統計每小時的請求數,top100的時間點(精確到小時)
-
awk '{print $4}' access.log |cut -c 14-15|sort|uniq -c|sort -nr|head -n 100
統計每秒的請求數,top100的時間點(精確到秒)
-
awk '{print $4}' access.log |cut -c 14-21|sort|uniq -c|sort -nr|head -n 100
統計當天的 pv
-
grep "10/May/2018" access.log | wc -l
說明：
-
awk ‘{ print $4}’：取資料的第4域（第4列）
-
sort：進行排序。
-
uniq -c：列印每一重複行出現的次數。（並去掉重複行）
-
sort -nr：按照重複行出現的次序倒序排列。
-
head -n 100：取排在前100位的IP
頁面響應時間相關統計
可以使用下面的命令統計出所有響應時間超過 3 秒的日誌記錄。
-
awk '($NF > 1){print $11}' access.log
注意：NF 是當前記錄中域的個數。$NF 即最後一個域。
列出 php 頁面請求時間超過3秒的頁面，並統計其出現的次數，顯示前100條
-
cat access.log|awk '($NF > 1 && $7~/\.php/){print $7}'|sort -n|uniq -c|sort -nr|head -100
列出相應時間超過 5 秒的請求，顯示前20條
-
awk '($NF > 1){print $11}' access.log | awk -F\" '{print $2}' |sort -n| uniq -c|sort -nr|head -20
蜘蛛抓取統計
統計蜘蛛抓取次數
-
grep 'Baiduspider' access.log |wc -l
統計蜘蛛抓取404的次數
-
grep 'Baiduspider' access.log |grep '404' | wc -l
小結
通過本文的介紹，我相信同學們一定會發現 linux三劍客強大之處。在命令列中，它還能夠接受和執行外部的 AWK 程式檔案，支援對文字資訊進行非常複雜的處理，可以說“只有想不到的，沒有它做不到的”。