《如何挖掘Nginx日志中隱藏的金礦？》要點(diǎn)：
本文介紹了如何挖掘Nginx日志中隱藏的金礦？，希望對(duì)您有用。如果有疑問(wèn)，可以聯(lián)系我們。

對(duì)很多開(kāi)發(fā)運(yùn)維人員來(lái)說(shuō),Nginx日志文件在被刪除前可能都不會(huì)看上一眼.但實(shí)際上,Nginx隱藏了相當(dāng)豐富的信息,或許其中便蘊(yùn)含著未知的金礦等你挖掘!

Nginx(讀作Engine-X)是現(xiàn)在最流行的負(fù)載均衡和反向代理服務(wù)器之一.如果你是一名中小微型網(wǎng)站的開(kāi)發(fā)運(yùn)維人員,很可能像我們一樣,僅Nginx每天就會(huì)產(chǎn)生上百M(fèi)甚至數(shù)以十G的日志文件.如果沒(méi)有出什么錯(cuò)誤,在被logrotate定期分割并滾動(dòng)刪除以前,這些日志文件可能都不會(huì)被看上一眼.

實(shí)際上,Nginx日志文件可以記錄的信息相當(dāng)豐富,而且格式可以定制,考慮到`$time_local`請(qǐng)求時(shí)間字段幾乎必有,這是一個(gè)典型的基于文件的時(shí)間序列數(shù)據(jù)庫(kù).Nginx日志被刪除以前,或許我們可以想想,其中是否蘊(yùn)含著未知的金礦等待挖掘?

請(qǐng)求訪問(wèn)分析

Nginx中的每條記錄是一個(gè)單獨(dú)的請(qǐng)求,可能是某個(gè)頁(yè)面或靜態(tài)資源的訪問(wèn),也可能是某個(gè)API的調(diào)用.通過(guò)幾條簡(jiǎn)單的命令,了解一下系統(tǒng)的訪問(wèn)壓力：

// 請(qǐng)求總數(shù) ? ? 
?less main.log | wc -l ? 
?1080577 ? ? ? ? 
?// 平均每秒的請(qǐng)求數(shù) ? ?
less main.log | awk '{sec=substr($4,2,20);reqs++;reqsBySec[sec]++;} END{print reqs/length(reqsBySec)}' ? ?14.0963 ? ? ? ? ?
// 峰值每秒請(qǐng)求數(shù) ? 
?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

請(qǐng)求總數(shù)、平均每秒請(qǐng)求數(shù)、峰值請(qǐng)求數(shù),可以大體了解系統(tǒng)壓力,作為系統(tǒng)擴(kuò)容、性能及壓力測(cè)試時(shí)的直接參考.查詢特定的URL,比如下單頁(yè)面,了解每天的下單狀況,導(dǎo)出CSV格式,或使用可視化工具,更直觀地了解一段時(shí)間內(nèi)的請(qǐng)求、下單數(shù)據(jù)：

備注：本文使用awk命令處理,與Nginx日志的格式有關(guān),如果您格式不同,請(qǐng)酌情修改命令.本文所用的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日志如果開(kāi)啟,除了請(qǐng)求時(shí)間,一般會(huì)包含響應(yīng)時(shí)間、頁(yè)面尺寸等字段,據(jù)此很容易計(jì)算出網(wǎng)絡(luò)流量、速率.

等等,你可能會(huì)有疑問(wèn),上面的請(qǐng)求訪問(wèn)分析,這里的流量速率分析,按時(shí)間軸畫出來(lái),不就是監(jiān)控系統(tǒng)干的事兒?jiǎn)?何苦這么麻煩查詢Nginx日志?

的確如此,監(jiān)控系統(tǒng)提供了更實(shí)時(shí)、更直觀的方式.而Nginx日志文件的原始數(shù)據(jù),可以從不同維度分析,使用得當(dāng),會(huì)如大浪淘沙般,發(fā)現(xiàn)屬于我們的金子.

對(duì)一般網(wǎng)站來(lái)說(shuō),帶寬是最珍貴的資源,可能一不小心,某些資源如文件、圖片就占用了大量的帶寬,執(zhí)行命令檢查一下：

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響應(yīng)體的大小,如果想查看整個(gè)響應(yīng)的大小,應(yīng)該使用變量$sent_size.

不出意外,靜態(tài)資源、圖片類(如果還沒(méi)有放CDN)占據(jù)榜首,自然也是優(yōu)化的重點(diǎn)：是否可以再壓縮,某些頁(yè)面中是否可以用縮略圖片代替等.

與之相比,后臺(tái)調(diào)用、API接口等通常消耗更多的CPU資源,按照一貫“先衡量、再優(yōu)化”的思路,可以根據(jù)響應(yīng)時(shí)間大體了解某個(gè)URL占用的CPU時(shí)間：

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

不對(duì),發(fā)現(xiàn)一個(gè)問(wèn)題：由于擁有服務(wù)號(hào)、App、PC瀏覽器等多種前端,并且使用不規(guī)范,URL的格式可能亂七八糟.比如`/page/a`頁(yè)面,有的帶有.html后綴,有的未帶,有的請(qǐng)求路徑則帶有參數(shù)；分類頁(yè)/categories/food帶有`slug`等信息；訂單、詳情或個(gè)人中心的URL路徑則有`ID`等標(biāo)記….

借助sed命令,通過(guò)三個(gè)方法對(duì)URL格式進(jìn)行歸一化處理：去掉所有的參數(shù)；去掉`.html`及`.json`后綴；把數(shù)字替換為`*`.可以得到更準(zhǔn)確的統(tǒng)計(jì)結(jié)果,：

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

備注：這里使用了擴(kuò)展正則表達(dá)式,GNU sed的參數(shù)為-r,BSD sed的參數(shù)為-E.

那些累計(jì)占用了更多響應(yīng)時(shí)間的請(qǐng)求,通常也耗用了更多的CPU時(shí)間,是性能優(yōu)化重點(diǎn)照顧的對(duì)象.

慢查詢分析

“服務(wù)號(hào)剛推送了文章,有用戶反映點(diǎn)開(kāi)很慢”,你剛端起桌子上的水杯,就聽(tīng)到產(chǎn)品經(jīng)理的大嗓門從辦公室角落呼嘯而來(lái).“用戶用的什么網(wǎng)絡(luò)”,你一邊問(wèn)著,一邊打開(kāi)服務(wù)號(hào)親自嘗試一下.是用戶網(wǎng)絡(luò)環(huán)境不好,還是后臺(tái)系統(tǒng)有了訪問(wèn)壓力?是這一個(gè)用戶慢,還是很多用戶都慢?你一邊腦子里在翻騰,一邊又打開(kāi)命令行去查看日志.

與PC瀏覽器相比,微信服務(wù)號(hào)在網(wǎng)絡(luò)環(huán)境、頁(yè)面渲染上有較大的掣肘,在緩存策略上也不如APP自如,有時(shí)會(huì)遇到詭異的問(wèn)題.如果手里恰好有Nginx日志,能做點(diǎn)什么呢?

考慮一下MySQL數(shù)據(jù)庫(kù),可以打開(kāi)慢查詢功能,定期查找并優(yōu)化慢查詢,與此類似,Nginx日志中的響應(yīng)時(shí)間,不相當(dāng)于自帶慢查詢功能嘛.利用這一特性,我們分步進(jìn)行慢查詢分析：

第一步：是不是用戶的網(wǎng)絡(luò)狀況不好?根據(jù)既往的經(jīng)驗(yàn),如果只有少量的請(qǐng)求較慢,而前后其他IP的請(qǐng)求都較快,通常是用戶手機(jī)或網(wǎng)絡(luò)狀況不佳引起的.最簡(jiǎn)單的方法,統(tǒng)計(jì)慢查詢所占比例：

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

慢查詢所占比例極低,再根據(jù)用戶手機(jī)型號(hào)、訪問(wèn)時(shí)間、訪問(wèn)頁(yè)面等信息看能否定位到指定的請(qǐng)求,結(jié)合前后不同用戶的請(qǐng)求,就可以確定是否用戶的網(wǎng)絡(luò)狀況不好了.

第二步：是不是應(yīng)用系統(tǒng)的瓶頸?對(duì)比應(yīng)用服務(wù)器的返回時(shí)間($upstream_response_time字段),與Nginx服務(wù)器的處理時(shí)間($request_time字段),先快速排查是否某一臺(tái)服務(wù)器抽風(fēng).

我們遇到過(guò)類似問(wèn)題,平均響應(yīng)時(shí)間90ms,還算正常,但某臺(tái)服務(wù)器明顯變慢,平均響應(yīng)時(shí)間達(dá)到了200ms,影響了部分用戶的訪問(wèn)體驗(yàn).

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

不幸,市場(chǎng)部此次推廣活動(dòng),訪問(wèn)壓力增大,所有服務(wù)器都在變慢,更可能是應(yīng)用系統(tǒng)的性能達(dá)到了瓶頸.如果此時(shí)帶寬都沒(méi)跑滿,在硬件擴(kuò)容之前,考慮優(yōu)化重點(diǎn)API、緩存、靜態(tài)化策略吧,達(dá)到一個(gè)基本的要求：“優(yōu)化系統(tǒng),讓瓶頸落到帶寬上”.

第三步：應(yīng)用系統(tǒng)沒(méi)有瓶頸,是帶寬的問(wèn)題?快速查看一下每秒的流量：

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的帶寬統(tǒng)計(jì),做定向優(yōu)化,或者加帶寬吧.

還能做哪些優(yōu)化?

SEO團(tuán)隊(duì)抱怨優(yōu)化了那么久,為什么頁(yè)面索引量和排名上不去.打印出不同爬蟲(chóng)的請(qǐng)求頻次($http_user_agent),或者查看某個(gè)特定的頁(yè)面,最近有沒(méi)有被爬蟲(chóng)爬過(guò)：

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

數(shù)據(jù)告訴我們,頁(yè)面索引量上不去,不一定是某個(gè)爬蟲(chóng)未檢索到頁(yè)面,更多的是其他原因.

市場(chǎng)團(tuán)隊(duì)要上一個(gè)新品并且做促銷活動(dòng),你建議避開(kāi)周一周五,因?yàn)橹苋芩牡霓D(zhuǎn)化率更高：

周三、周四的轉(zhuǎn)換率比周末高不少,可能跟平臺(tái)的發(fā)貨周期有關(guān),客戶周三四下單,希望周末就能收到貨,開(kāi)始快樂(lè)的周末.你猜測(cè)到用戶的心理和期望,連數(shù)據(jù)一起交市場(chǎng)品團(tuán)隊(duì),期待更好地改善.

這樣的例子可以有很多.事實(shí)上,上述分析限于Nginx日志,如果有系統(tǒng)日志,并且日志格式定義良好,可以做的事情遠(yuǎn)不止于此：這是一個(gè)時(shí)間序列數(shù)據(jù)庫(kù),可以查詢IT系統(tǒng)的運(yùn)行情況,可以分析營(yíng)銷活動(dòng)的效果,也可以預(yù)測(cè)業(yè)務(wù)數(shù)據(jù)的趨勢(shì)；這是一個(gè)比較小但夠用的大數(shù)據(jù)源,運(yùn)用你學(xué)會(huì)的大數(shù)據(jù)分析方法,也可以像滴滴那樣,分并預(yù)測(cè)不同天氣、時(shí)間段下不同地區(qū)的車輛供需,并作出優(yōu)化.

幾點(diǎn)建議

1. 規(guī)范日志格式.這是很多團(tuán)隊(duì)容易忽略的地方,有時(shí)候多一個(gè)空格會(huì)讓日志分析的復(fù)雜度大為增加.
2. 無(wú)論如何,使用時(shí)間戳字段.以時(shí)間序列的方式看待日志文件,這也是很多公司把系統(tǒng)日志直接寫入到時(shí)間序列數(shù)據(jù)庫(kù)的原因；
3. 如有可能,記錄以下字段：用戶(或者客戶端)標(biāo)識(shí)、單次請(qǐng)求標(biāo)識(shí)、應(yīng)用標(biāo)識(shí)(如果單次請(qǐng)求會(huì)走到多個(gè)應(yīng)用).能夠方便地查出用戶鏈路、請(qǐng)求鏈路,是排查錯(cuò)誤請(qǐng)求、分析用戶行為的基礎(chǔ)；
4. 關(guān)注寫的操作.就像業(yè)務(wù)建模時(shí),需要特別關(guān)注具有時(shí)標(biāo)性、狀態(tài)會(huì)發(fā)生改變的模型一樣,任何寫的操作,都應(yīng)記錄到日志系統(tǒng)中.萬(wàn)一某個(gè)業(yè)務(wù)出錯(cuò),不但可以通過(guò)業(yè)務(wù)模型復(fù)演,也可以通過(guò)日志系統(tǒng)復(fù)演.
5. 規(guī)范URL格式.這一點(diǎn)同樣容易遭到忽略,商品詳情頁(yè)面要不要添加”?from=XXX”來(lái)源參數(shù)?支付頁(yè)面采用路徑標(biāo)記“payment/alipay”,還是參數(shù)標(biāo)記“/payment?type=alipay”更合適?區(qū)別細(xì)微但影響不可忽略.

技術(shù)團(tuán)隊(duì)?wèi)?yīng)該像對(duì)待協(xié)議一樣對(duì)待這些規(guī)范.仔細(xì)定義并嚴(yán)格遵守,相當(dāng)于拿到了金礦的鑰匙.

還需要尋找一個(gè)合適的日志分析工具,基于Python、Go、Lua,都有免費(fèi)的日志分析工具可供使用；想更輕量,準(zhǔn)備幾條常用的shell腳本,比如作者整理了一些到GitHub的這個(gè)項(xiàng)目上(https://github.com/aqingsao/nana)；或者基于ELK技術(shù)棧,把Nginx訪問(wèn)日志、業(yè)務(wù)日志統(tǒng)一存儲(chǔ),并通過(guò)Kibana進(jìn)行不同維度的聚合分析,都是不錯(cuò)的辦法.

或許你早就使用Nginx日志了,你是怎么使用的,有什么好的方法呢,歡迎一起交流.

文章來(lái)源：InfoQ

作者：張曉慶

轉(zhuǎn)載請(qǐng)注明本頁(yè)網(wǎng)址：
http://www.snjht.com/jiaocheng/4419.html