(項目最新進展請見github)html
This tool aim at trouble shooting and performance optimization based on web logs, it's not a generally said log analyse/statistics solution. It preprocess logs on all web server with a specified period and save the intermediate results into mongodb for finally use(with log_show.py
)python
日誌分析在平常中故障排查、性能分析方面有着很是重要的做用。該項目的側重點不是一般的PV,UV等展現,而是在指定時間段內提供細粒度(最小分鐘級別)的異常定位和性能分析。ios
先明確幾個術語: uri
指不包含參數的請求;request_uri
指原始的請求,包含參數;args
指請求中的參數部分。(參照nginx中的定義)uri_abs
和args_abs
是指對uri和args進行抽象處理後的字符串(以便分類),例如: "/sub/0/100414/4070?channel=ios&version=1.4.5"
經抽象處理轉換爲uri_abs:
"/sub/*/*/*",args_abs:
"channel=*&version=*"nginx
時間段
和server
兩個維度進行過濾request_uri
,ip
和 response_code
三大類進行分析;每一類又基於請求數
、響應大小
、響應時間
三個維度進行分析。另外不一樣子項又各有特色request_uri
分析能直觀展現哪類請求數量多、哪類請求耗時多、哪類請求佔流量;另外可展現某一類請求在不一樣時間粒度裏(minute, ten_min, hour, day)各指標隨時間的分佈變化;也能夠針對某一 uri_abs 分析其不一樣 args_abs 各指標的分佈響應時間
和響應大小
更準確的描述,由於對於日誌中的響應時間,算數平均值的參考意義不大 分析腳本(log_analyse.py
)部署到各臺web server,並經過crontab設置定時運行。log_analyse.py
利用python的re模塊經過正則表達式對日誌進行分析處理,取得uri
、args
、時間當前
、狀態碼
、響應大小
、響應時間
、server name
等信息並進行初步加工而後存儲進MongoDB。查看腳本(log_show.py
)做爲入口便可對全部web server的日誌進行分析查看,至於實時性,取決於web server上log_analyse.py
腳本的執行頻率。git
日誌格式決定了代碼中的正則表達式,可根據本身狀況參考config.py
中的正則定義進行定製)。項目中預約義的日誌格式對應以下:github
LOG_FORMAT = '$remote_addr - [$time_local] "$request" '\ '$status $body_bytes_sent $request_time "$http_referer" '\ '"$http_user_agent" - $http_x_forwarded_for'
若是想靠空格或雙引號來分割各段的話,主要問題是面對各類不規範的記錄時(緣由不一而足,並且也是樣式繁多),沒法作到將各類異常都考慮在內,因此項目中採用了re
模塊而不是簡單的split()
函數。代碼裏對一些「能夠容忍」的異常記錄經過一些判斷邏輯予以處理;對於「沒法容忍」的異常記錄則返回空字符串並將日誌記錄於文件。
其實對於上述的這些不規範的請求,最好的辦法是在nginx中定義日誌格式時,用一個特殊字符做爲分隔符,例如「|」。這樣就不須要re模塊,直接字符串分割就能正確的獲取到各段(性能會好些)。web
[ljk@demo ~]$ log_show --help Usage: log_show <site_name> [options] request [distribution [<request>]|detail <uri>] log_show <site_name> [options] ip [distribution <ip>|detail <ip>] log_show <site_name> [options] error [distribution <error_code>|detail <error_code>] Options: -h --help Show this screen. -f --from <start_time> Start time. Format: %y%m%d[%H[%M]], %H and %M is optional -t --to <end_time> End time. Format is same as --from -l --limit <num> Number of lines in output, 0 means no limit. [default: 5] -s --server <server> Web server hostname -g --group_by <group_by> Group by every minute, every ten minutes, every hour or every day, valid values: "minute", "ten_min", "hour", "day". [default: hour] distribution Show distribution(about hits,bytes,time,etc) of: all or specific 'request', the specific 'ip', the specific 'error_code' in every period. Period is specific by --group_by detail Show details of: detail 'args' analyse of the specific 'uri'(if it has args); detail 'uri' analyse of the specific 'ip' or 'error_code' Notice: it's best to put 'request_uri', 'uri' and 'ip' in quotation marks.
全部示例都可經過-f
,-t
,-s
參數對起始時間
和指定server
進行過濾 正則表達式
對指定站點今日已入庫的數據進行分析mongodb
[ljk@demo ~]$ log_show api request -l 3 ==================== Total_hits:×××05 invalid_hits:581 ==================== hits percent time_distribution(s) bytes_distribution(B) uri_abs 430210 43.06% %50<0.03 %75<0.06 %100<2.82 %50<61 %75<63 %100<155 /api/record/getR 183367 18.35% %50<0.03 %75<0.06 %100<1.73 %50<196 %75<221 %100<344 /api/getR/com/*/*/* 102299 10.24% %50<0.02 %75<0.05 %100<1.77 %50<3862 %75<3982 %100<4512 /view/*/*/*/*.js ==================== Total_bytes:1.91 GB ==================== bytes percent time_distribution(s) bytes_distribution(B) uri_abs 1.23 GB 64.61% %50<0.04 %75<0.1 %100<1.96 %50<17296 %75<31054 %100<691666 /api/NewCom/list 319.05 MB 16.32% %50<0.02 %75<0.05 %100<1.77 %50<3862 %75<3982 %100<4512 /view/*/*/*/*.js 167.12 MB 8.55% %50<0.19 %75<0.55 %100<2.93 %50<3078 %75<3213 %100<11327 /api/getR/com/*/* ==================== Total_time:117048s ==================== cum. time percent time_distribution(s) bytes_distribution(B) uri_abs 38747 33.10% %50<0.03 %75<0.06 %100<2.82 %50<61 %75<63 %100<155 /api/record/getR 22092 18.87% %50<0.03 %75<0.06 %100<1.73 %50<196 %75<221 %100<344 /api/getR/com/*/*/* 17959 15.34% %50<0.19 %75<0.55 %100<2.93 %50<3078 %75<3213 %100<11327 /api/getRInfo/com/*/*
經過上例可觀察指定時間內(默認當天0時至當前時間)hits/bytes/time三個維度的排名以及響應時間和響應大小的分佈狀況。例如,看到某個uri_abs只有比較少的hits確產生了比較大的bytes或耗費了較多的time,那麼該uri_abs是否值得關注一下呢。 json
顯示基於ip地址的分析結果
[ljk@demo ~]$ log_show.py api ip -l 2 ==================== From_cdn/Proxy: hits hits(%) bytes bytes(%) time(%) ==================== 199870 99.94 570.51 MB 99.99 99.99 Last_cdn_ip xxx.57.xxx.189 1914 0.96 696.18 KB 0.12 0.68 xxx.206.xxx.154 1741 0.87 1.56 MB 0.27 0.98 User_ip_via_cdn xxx.249.xxx.56 787 0.39 154.82 KB 0.03 0.23 xxx.60.xxx.86 183 0.09 1.05 MB 0.18 0.13 ==================== From_reverse_proxy: hits hits(%) bytes bytes(%) time(%) ==================== 66 0.03 68.83 KB 0.01 0.01 User_ip_via_proxy xxx.188.xxx.21 2 0.00 1.53 KB 0.00 0.00 xxx.5.xxx.4 2 0.00 324.00 B 0.00 0.00 ==================== From_client_directly: hits hits(%) bytes bytes(%) time(%) ==================== 64 0.03 8.32 KB 0.00 0.00 Remote_addr 192.168.1.202 29 0.01 58.00 B 0.00 0.00 192.168.1.200 29 0.01 58.00 B 0.00 0.00
IP分析的思想是將請求按來源歸爲三大類:From_cdn/Proxy,From_reverse_proxy,From_client_directly,而後各自分類內按請求次數對IP地址進行排序
適用場景:查看request/IP隨時間在各聚合粒度內各項指標的變化狀況,例如針對某個uri發現其請求數(或帶寬)變大,則可經過distribution
子命令觀察是某一段時間忽然變大呢,仍是比較平穩的變大
# 示例1: 分析指定request的分佈狀況, 指定按minute進行分組聚合, 默認顯示5行 [ljk@demo ~]$ python log_show.py api request distribution "/view/*/*.json" -g minute ==================== uri_abs: /view/*/*.json Total_hits: 17130 Total_bytes: 23.92 MB ==================== minute hits hits(%) bytes bytes(%) time_distribution(s) bytes_distribution(B) 201803091654 1543 9.01% 2.15 MB 8.98% %50<0.03 %75<0.05 %100<1.07 %50<1593 %75<1645 %100<1982 201803091655 1527 8.91% 2.13 MB 8.88% %50<0.04 %75<0.05 %100<1.04 %50<1592 %75<1642 %100<2143 201803091656 1464 8.55% 2.05 MB 8.57% %50<0.04 %75<0.05 %100<1.03 %50<1592 %75<1642 %100<1952 201803091657 1551 9.05% 2.15 MB 8.97% %50<0.03 %75<0.04 %100<0.89 %50<1594 %75<1639 %100<1977 201803091658 1458 8.51% 2.06 MB 8.61% %50<0.03 %75<0.04 %100<2.35 %50<1596 %75<1644 %100<2146
經過上例,可展現"/view/*/*.json"在指定時間段內的分佈狀況,包括hits/bytes/time總量以及每一個粒度內個指標相對於總量的佔比;該子命令亦能展現各指標隨時間的「趨勢」。
說明:
minute字段爲指定的聚合(group)粒度,1803091654 表示「18年03月09日16時54分」
可經過-g
參數指定聚合的粒度(minute/ten_min/hour/day) distribution
子命令後能夠跟具體的uri/request_uri(顯示該uri/request_uri以指定粒度隨時間的分佈)或不跟uri(顯示全部請求以指定粒度隨時間的分佈)
# 示例2: 分析指定IP產生的請求數/帶寬隨時間分佈狀況, 默認聚合粒度爲hour [ljk@demo ~]$ python log_show.py api ip -t 180314 distribution "140.206.109.174" -l 0 ==================== IP: 140.206.109.174 Total_hits: 10999 Total_bytes: 4.83 MB ==================== hour hits hits(%) bytes bytes(%) 2018031306 1273 11.57% 765.40 KB 15.47% 2018031307 2133 19.39% 1004.74 KB 20.31% 2018031308 2211 20.10% 1.00 MB 20.74% 2018031309 2334 21.22% 1.05 MB 21.72% 2018031310 2421 22.01% 850.79 KB 17.20% 2018031311 627 5.70% 226.30 KB 4.57%
說明:
hour字段表示默認的聚合粒度,18031306表示「18年03月13日06時」
-l 0 表示不限制輸出行數(即輸出全部結果)
適用場景:好比定位到某一類型的uri_abs在某方面(hits/bytes/time)有異常,就能夠經過detail子命令對該類uri_abs進行更近一步的分析,精肯定位到是哪一種參數(args_abs)致使的異常;或者觀察到某個IP訪問異常,能夠再深刻一下該IP是泛泛的訪問呢,仍是隻對某些uri感興趣。
# 示例1: [ljk@demo ~]$ python log_show.py api -f 180201 request detail "/recommend/update" -l 3 ==================== uri_abs: /recommend/batchUpdate Total_hits: 10069 Total_bytes: 7.62 MB ==================== hits hits(%) bytes bytes(%) time(%) time_distribution(s) bytes_distribution(B) args_abs 4568 45.37% 3.46 MB 45.44% 47.96% %50<0.06 %75<0.07 %100<0.47 %50<795 %75<845 %100<1484 uid=*&category_id=*&channel=*&version=* 4333 43.03% 3.25 MB 42.64% 42.30% %50<0.05 %75<0.07 %100<0.48 %50<791 %75<840 %100<1447 category_id=*&channel=*&uid=*&version=* 389 3.86% 314.15 KB 4.03% 0.88% %50<0.03 %75<0.04 %100<0.06 %50<802 %75<850 %100<1203 category_id=*&channel=*&version=*
經過上例可觀察到"/recommend/update"這個uri所對應的不一樣參數各個指標的狀況。另外還有一個附帶的發現:開發在書寫參數時相同的參數組合沒有按同一個順序書寫,雖不影響功能,但在精準的進行應用性能監控的時候會形成必定困擾。
說明: detail
子命令後跟隨uri(不含參數,含參數的話將忽略參數)
# 示例2: 觀察某個IP分別產生了多少種請求, 每種請求的(hits/bytes/time)指標 [ljk@demo ~]$ python log_show.py m -t 180314 ip detail "1.2.3.4" ==================== IP: 140.206.109.174 Total_hits: 10999 Total_bytes: 4.83 MB ==================== hits hits(%) bytes bytes(%) time(%) uri_abs 10536 95.79% 405.47 KB 8.19% 92.01% /introduction/watch 147 1.34% 1.90 MB 39.31% 1.93% /view/*/*.html 138 1.25% 407.42 KB 8.23% 2.41% /chapinfo/*/*.html 42 0.38% 644.88 KB 13.03% 1.38% /info/*.html 30 0.27% 229.98 KB 4.65% 1.14% /classify/*.json
該腳本的設計目標是將其放到web server的的計劃任務裏,定時(例如每30分鐘或10分鐘,自定義)執行,在須要時經過log_show.py進行分析便可。
*/15 * * * * export LANG=zh_CN.UTF-8;python3 /home/ljk/log_analyse.py &> /tmp/log_analyse.log
uri_abs
和args_abs
是對uri和args進行抽象化(抽象出特定的請求模式,即將請求分類看待)處理以後的結果,默認規則以下 common/common.py
中還有一些其餘有趣的函數