Nginx日志中的金礦
Nginx （讀作Engine-X）是現在最流行的負載均衡和反向代理服務器之一。如果你是一名中小微型網站的開發運維人員，很可能像我們一樣，僅Nginx每天就會產生上百M甚至數以十G的日志文件。如果沒有出什么錯誤，在被 logrotate 定期分割并滾動刪除以前，這些日志文件可能都不會被看上一眼。
實際上，Nginx日志文件可以記錄的信息 相當豐富 ，而且格式可以定制，考慮到`$time_local`請求時間字段幾乎必有，這是一個典型的基于文件的時間序列數據庫。Nginx日志被刪除以前，或許我們可以想想，其中是否蘊含著未知的金礦等待挖掘？
請求訪問分析
Nginx中的每條記錄是一個單獨的請求，可能是某個頁面或靜態資源的訪問，也可能是某個API的調用。通過幾條簡單的命令，了解一下系統的訪問壓力：
// 請求總數
less main.log | wc -l
1080577
// 平均每秒的請求數
less main.log | awk '{sec=substr($4,2,20);reqs++;reqsBySec[sec]++;} END{print reqs/length(reqsBySec)}'
14.0963
// 峰值每秒請求數
less main.log | awk '{sec=substr($4,2,20);requests[sec]++;} END{for(s in requests){printf("%s %s\n", requests[s],s)}}' | sort -nr | head -n 3
Page Visits Response Size Time Spent/req Moment
182 10/Apr/2016:12:53:20
161 10/Apr/2016:12:54:53
160 10/Apr/2016:10:47:23
請求總數、平均每秒請求數、峰值請求數，可以大體了解系統壓力，作為系統擴容、性能及壓力測試時的直接參考。查詢特定的URL，比如下單頁面，了解每天的下單狀況，導出CSV格式，或使用可視化工具，更直觀地了解一段時間內的請求、下單數據：
備注：本文使用awk命令處理，與Nginx日志的格式有關，如果您格式不同，請酌情修改命令。本文所用的Nginx日志格式：
$remote_addr - $remote_user [$time_local] "$request" $status $body_bytes_sent $request_time $upstream_response_time $upstream_addr "$http_referer" "$http_user_agent" "$http_x_forwarded_for"';
示例：
42.100.52.XX - - [10/Apr/2016:07:29:58 +0800] "GET /index HTTP/1.1" 200 7206 0.092 0.092 "-" "Mozilla/5.0 (iPhone; CPU iPhone OS 7_1_2 like Mac OS X) AppleWebKit/537.51.2 (KHTML, like Gecko) Mobile/11D257" "-"
流量速率分析
Nginx日志如果開啟，除了請求時間，一般會包含響應時間、頁面尺寸等字段，據此很容易計算出網絡流量、速率。
等等，你可能會有疑問，上面的請求訪問分析，這里的流量速率分析，按時間軸畫出來，不就是監控系統干的事兒嗎，何苦這么麻煩查詢Nginx日志？
的確如此，監控系統提供了更實時、更直觀的方式。而Nginx日志文件的原始數據，可以從不同維度分析，使用得當，會如大浪淘沙般，發現屬于我們的金子。
對一般網站來說，帶寬是最珍貴的資源，可能一不小心，某些資源如文件、圖片就占用了大量的帶寬，執行命令檢查一下：
less static.log | awk 'url=$7; requests[url]++;bytes[url]+=$10}
END{for(url in requests){printf("%sMB %sKB/req %s %s\n", bytes[url] /
1024 / 1024, bytes[url] /requests[url] / 1024, requests[url], url)}}' | sort -nr | head -n 15
備注：Nginx配置文件中日志格式使用了$body_sent_size，指HTTP響應體的大小，如果想查看整個響應的大小，應該使用變量$sent_size。
不出意外，靜態資源、圖片類（如果還沒有放CDN）占據榜首，自然也是優化的重點：是否可以再壓縮，某些頁面中是否可以用縮略圖片代替等。
與之相比，后臺調用、API接口等通常消耗更多的CPU資源，按照一貫“先衡量、再優化”的思路，可以根據響應時間大體了解某個URL占用的CPU時間：
less main.log | awk '{url=$7; times[url]++} END{for(url in
times){printf("%s %s\n", times[url], url)}}' | sort -nr | more`
40404 /page/a?from=index
1074 /categories/food
572 /api/orders/1234.json
不對，發現一個問題：由于擁有服務號、App、PC瀏覽器等多種前端，并且使用不規范，URL的格式可能亂七八糟。比如`/page/a`頁面，有的帶有.html后綴，有的未帶，有的請求路徑則帶有參數；分類頁/categories/food帶有`slug`等信息；訂單、詳情或個人中心的URL路徑則有`ID`等標記...。
借助sed命令，通過三個方法對URL格式進行歸一化處理：去掉所有的參數；去掉`.html`及`.json`后綴；把數字替換為`*`。可以得到更準確的統計結果，：
less main.log | awk '{print $7}' |sed -re 's/(.*)\?.*/\1/g' -e
's/(.*)\..*/\1/g' -e 's:/[0-9]+:/*:g' | awk '{requests[$1]++;time[$1]
+=$2} END{for(url in requests){printf("%smin %ss/req %s %s\n", time
[url] / 60, time[url] /requests[url], requests[url], url)}}' | sort -nr | head -n 50
備注：這里使用了擴展正則表達式，GNU sed的參數為-r，BSD sed的參數為-E。
那些累計占用了更多響應時間的請求，通常也耗用了更多的CPU時間，是性能優化重點照顧的對象。
慢查詢分析
“服務號剛推送了文章，有用戶反映點開很慢”，你剛端起桌子上的水杯，就聽到產品經理的大嗓門從辦公室角落呼嘯而來。“用戶用的什么網絡”，你一邊問著，一邊打開服務號親自嘗試一下。是用戶網絡環境不好，還是后臺系統有了訪問壓力？是這一個用戶慢，還是很多用戶都慢？你一邊腦子里在翻騰，一邊又打開命令行去查看日志。
與PC瀏覽器相比，微信服務號在網絡環境、頁面渲染上有較大的掣肘，在緩存策略上也不如APP自如，有時會遇到詭異的問題。如果手里恰好有Nginx日志，能做點什么呢？
考慮一下MySQL數據庫，可以打開慢查詢功能，定期查找并優化慢查詢，與此類似，Nginx日志中的響應時間，不相當于自帶慢查詢功能嘛。利用這一特性，我們分步進行慢查詢分析：
第一步：是不是用戶的網絡狀況不好？根據既往的經驗，如果只有少量的請求較慢，而前后其他IP的請求都較快，通常是用戶手機或網絡狀況不佳引起的。最簡單的方法，統計慢查詢所占比例：
less main.log | awk -v limit=2 '{min=substr($4,2,17);reqs[min]
++;if($11>limit){slowReqs[min]++}} END{for(m in slowReqs){printf("%s
%s %s%s %s\n", m, slowReqs[m]/reqs[m] * 100, "%", slowReqs[m], reqs
[m])}}' | more
10/Apr/2016:12:51 0.367% 7 1905
10/Apr/2016:12:52 0.638% 12 1882
10/Apr/2016:12:53 0.548% 14 2554
慢查詢所占比例極低，再根據用戶手機型號、訪問時間、訪問頁面等信息看能否定位到指定的請求，結合前后不同用戶的請求，就可以確定是否用戶的網絡狀況不好了。
第二步：是不是應用系統的瓶頸？對比應用服務器的返回時間($upstream_response_time字段），與Nginx服務器的處理時間($request_time字段)，先快速排查是否某一臺服務器抽風。
我們遇到過類似問題，平均響應時間90ms，還算正常，但某臺服務器明顯變慢，平均響應時間達到了200ms，影響了部分用戶的訪問體驗。
less main.log | awk '{upServer=$13;upTime=$12;if(upServer ==
"-"){upServer="Nginx"};if(upTime == "-"){upTime=0};upTimes[upServer]
+=upTime;count[upServer]++;totalCount++;} END{for(server in upTimes)
{printf("%s %s%s %ss %s\n", count[server], count[server]/totalCount *
100, "%", upTimes[server]/count[server], server)}}' | sort -nr
不幸，市場部此次推廣活動，訪問壓力增大，所有服務器都在變慢，更可能是應用系統的性能達到了瓶頸。如果此時帶寬都沒跑滿，在硬件擴容之前，考慮優化重點API、緩存、靜態化策略吧，達到一個基本的要求：“優化系統，讓瓶頸落到帶寬上”。
第三步：應用系統沒有瓶頸，是帶寬的問題？快速查看一下每秒的流量：
less main.log | awk '{second=substr($4,2,20);bytes[second]+=$10;}
END{for(s in bytes){printf("%sKB %s\n", bytes[s]/1024, s)}}' | more`
1949.95KB 10/Apr/2016:12:53:15
2819.1KB 10/Apr/2016:12:53:16
3463.64KB 10/Apr/2016:12:53:17
3419.21KB 10/Apr/2016:12:53:18
2851.37KB 10/Apr/2016:12:53:19
峰值帶寬接近出口帶寬最大值了，幸福的煩惱，利用前面介紹的不同URL的帶寬統計，做定向優化，或者加帶寬吧。
還能做那些優化？
SEO團隊抱怨優化了那么久，為什么頁面索引量和排名上不去。打印出不同爬蟲的請求頻次（$http_user_agent），或者查看某個特定的頁面，最近有沒有被爬蟲爬過：
less main.log | egrep 'spider|bot' | awk '{name=$17;if(index
($15,"spider")>0){name=$15};spiders[name]++} END{for(name in spiders)
{printf("%s %s\n",spiders[name], name)}}' | sort -nr
數據告訴我們，頁面索引量上不去，不一定是某個爬蟲未檢索到頁面，更多的是其他原因。
市場團隊要上一個新品并且做促銷活動，你建議避開周一周五，因為周三周四的轉化率更高：
周三、周四的轉換率比周末高不少，可能跟平臺的發貨周期有關，客戶周三四下單，希望周末就能收到貨，開始快樂的周末。你猜測到用戶的心理和期望，連數據一起交市場品團隊，期待更好地改善。
這樣的例子可以有很多。事實上，上述分析限于Nginx日志，如果有系統日志，并且日志格式定義良好，可以做的事情遠不止于此：這是一個時間序列數據庫，可以查詢IT系統的運行情況，可以分析營銷活動的效果，也可以預測業務數據的趨勢；這是一個比較小但夠用的大數據源，運用你學會的大數據分析方法，也可以像滴滴那樣，分并預測不同天氣、時間段下不同地區的車輛供需，并作出優化。
幾點建議
- 規范日志格式。這是很多團隊容易忽略的地方，有時候多一個空格會讓日志分析的復雜度大為增加。
- 無論如何，使用時間戳字段。以時間序列的方式看待日志文件，這也是很多公司把系統日志直接寫入到時間序列數據庫的原因；
- 如有可能，記錄以下字段：用戶（或者客戶端）標識、單次請求標識、應用標識（如果單次請求會走到多個應用）。能夠方便地查出用戶鏈路、請求鏈路，是排查錯誤請求、分析用戶行為的基礎；
- 關注寫的操作。就像業務建模時，需要特別關注具有時標性、狀態會發生改變的模型一樣，任何寫的操作，都應記錄到日志系統中。萬一某個業務出錯，不但可以通過業務模型復演，也可以通過日志系統復演。
- 規范URL格式。這一點同樣容易遭到忽略，商品詳情頁面要不要添加"?from=XXX"來源參數？支付頁面采用路徑標記“payment/alipay”，還是參數標記“/payment?type=alipay”更合適？區別細微但影響不可忽略。
技術團隊應該像對待協議一樣對待這些規范。仔細定義并嚴格遵守，相當于拿到了金礦的鑰匙。
還需要尋找一個合適的日志分析工具，基于Python、Go、Lua，都有免費的日志分析工具可供使用；想更輕量，準備幾條常用的shell腳本，比如作者整理了一些到 GitHub的這個項目上 ；或者基于 ELK 技術棧，把Nginx訪問日志、業務日志統一存儲，并通過Kibana進行不同維度的聚合分析，都是不錯的辦法。
或許你早就使用Nginx日志了，你是怎么使用的，有什么好的方法呢，歡迎一起交流。
感謝張凱峰對本文的策劃，木環對本文的審校。
給InfoQ中文站投稿或者參與內容翻譯工作，請郵件至editors@cn.infoq.com。也歡迎大家通過新浪微博（@InfoQ，@丁曉昀），微信（微信號： InfoQChina ）關注我們。
來自：http://www.infoq.com/cn/articles/nignx-log-goldmine