歡迎光臨
每天分享高質量文章
當前位置：知識星球 > 後端 > 正文

Python老司機帶你快速搞定日誌分析工具

2018-03-23 分類：後端 閱讀(346) 評論(0)

轉載自：Python中文社群     ID:python-china


日誌分析在web系統中故障排查、效能分析方面有著非常重要的作用。該工具的側重點不是通常的PV，UV等展示，而是在指定時間段內提供細粒度（最小分鐘級別，即一分鐘內的日誌做抽象和彙總）的異常定位和效能分析。

環境安裝

  • Python 3.4+

  • pymongo 3.4.0+

  • MongoDB server

先明確幾個術語

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;=*”

特點

  1. 提供一個日誌分析的總入口：經由此入口，可檢視某站點所有 server 產生日誌的彙總分析；亦可根據 時間段和 server兩個維度進行過濾

  2. 支援對 requesturi，IP 和 responsecode 進行分析，基於 請求數、 響應大小、 響應時間三個大維度進行分析；另外不同子項又各有特點

  3. （核心思想）以某一類 uri 或其對應的各類 args 為維度進行分析，即對 requesturi 進行抽象處理將其分為 uriabs 和 args_abs 兩部分

  4. 3中提到的抽象歸類思想，預設抽象方法可滿足大部分需求；另外也提供了定製抽象規則的選項，基於此可靈活指定請求中的任何部分是否要抽象處理

  5. requesturi 分析能直觀展示哪類請求數量多、哪類請求耗時多、哪類請求佔流量；另外可展示某一類請求在不同粒度裡(minute, tenmin, hour, day)各指標隨時間的分佈變化；也可以針對某一 uriabs 分析其不同 argsabs 各指標的分佈

  6. IP 分析將所有請求分為3種來源(fromcdn/proxy, fromreverseproxy, fromclientdirectly)，三種來源各自展示其訪問量前 N 的 IP 地址；並且可展示某一 IP 訪問的各指標隨時間的分佈；也可針對某一 IP 分析其產生的不同 uriabs 各指標的分佈

  7. 透過4分位數概念以實現對 響應時間和 響應大小更準確的描述，因為對於日誌中的響應時間，算數平均值的參考意義不大

  8. 高效能：本著誰產生的日誌誰處理的思想，日誌分析指令碼loganalyse要在web伺服器上定時執行，因而loganalyse的高效率低資源也是重中之重。經測試，在筆者的伺服器上（磁碟：3*7200rpm組RAID5，千兆區域網），對於不同的日誌檔案，處理速度在20000行/s~30000行/s之間

實現思路

分析指令碼（ 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指令碼的執行頻率。

前提規範

  • 各臺server的日誌檔案按統一路徑存放

  • 日誌格式、日誌命名規則保持一致(程式碼中規定格式為xxx.access.log)

  • 每天的0點日誌切割

日誌格式決定了程式碼中的正則運算式，是可根據自己情況參考 analyse_config.py中的正則定義進行定製的)。專案中預定義的日誌格式對應如下：

  1. log_format  access  '$remote_addr - [$time_local] "$request" '

  2.              '$status $body_bytes_sent $request_time "$http_referer" '

  3.              '"$http_user_agent" - $http_x_forwarded_for';

對於其他格式的 nginx 日誌或者 Apache 日誌，按照如上原則，稍作就可以使用該工具分析處理。

對於異常日誌的處理

如果想靠空格或雙引號來分割各段的話，主要問題是面對各種不規範的記錄時(原因不一而足，而且也是樣式繁多)，無法做到將各種異常都考慮在內，所以專案中採用了 re模組而不是簡單的 split()函式的原因。程式碼裡對一些“可以容忍”的異常記錄透過一些判斷邏輯予以處理；對於“無法容忍”的異常記錄則傳回空字串並將日誌記錄於檔案。
其實對於上述的這些不規範的請求，最好的辦法是在nginx中定義日誌格式時，用一個特殊字元作為分隔符，例如“|”。這樣就不需要re模組，直接字串分割就能正確的獲取到各段(效能會好些)。

log_show.py使用說明：

幫助資訊

  1. [ljk@demo ~]$ log_show --help

  2. Usage:

  3.   log_show  [options] request [distribution [<request>]|detail ]

  4.   log_show  [options] ip [distribution |detail ]

  5.   log_show  [options] error [distribution |detail ]


  7. Options:

  8.   -h --help                   Show this screen.

  9.   -f --from       Start time. Format: %y%m%d[%H[%M]], %H and %M is optional

  10.   -t --to           End time. Format is same as --from

  11.   -l --limit             Number of lines in output, 0 means no limit. [default: 5]

  12.   -s --server         Web server hostname

  13.   -g --group_by     Group by every minute, every ten minutes, every hour or every day,

  14.                               valid values: "minute", "ten_min", "hour", "day". [default: hour]


  16.   distribution                Show distribution(about hits,bytes,time,etc) of:

  17.                               all or specific 'request', the specific 'ip', the specific 'error_code' in every period.

  18.                               Period is specific by --group_by

  19.   detail                      Show details of:

  20.                               detail 'args' analyse of the specific 'uri'(if it has args);

  21.                               detail 'uri' analyse of the specific 'ip' or 'error_code'


  23.   Notice: it's best to put 'request_uri', 'uri' and 'ip' in quotation marks.

所有示例均可透過 -f， -t， -s引數對 起始時間和 指定server進行過濾

request子命令

對指定站點今日已入庫的資料進行分析

  1. [ljk@demo ~]$ log_show api request -l 3

  2. ====================

  3. Total_hits:999205 invalid_hits:581

  4. ====================

  5.       hits  percent           time_distribution(s)                     bytes_distribution(B)              uri_abs

  6.     430210   43.06%  %25<0.01 %50<0.03 %75<0.06 %100<2.82   %25<42 %50<61 %75<63 %100<155                 /api/record/getR

  7.     183367   18.35%  %25<0.02 %50<0.03 %75<0.06 %100<1.73   %25<34 %50<196 %75<221 %100<344               /api/getR/com/*/*/*

  8.     102299   10.24%  %25<0.02 %50<0.02 %75<0.05 %100<1.77   %25<3263 %50<3862 %75<3982 %100<4512          /view/*/*/*/*.js

  9. ====================

  10. Total_bytes:1.91 GB

  11. ====================

  12.      bytes  percent           time_distribution(s)                     bytes_distribution(B)              uri_abs

  13.    1.23 GB   64.61%  %25<0.03 %50<0.04 %75<0.1 %100<1.96    %25<2549 %50<17296 %75<31054 %100<691666      /api/NewCom/list

  14.  319.05 MB   16.32%  %25<0.02 %50<0.02 %75<0.05 %100<1.77   %25<3263 %50<3862 %75<3982 %100<4512          /view/*/*/*/*.js

  15.  167.12 MB    8.55%  %25<0.15 %50<0.19 %75<0.55 %100<2.93   %25<2791 %50<3078 %75<3213 %100<11327         /api/getR/com/*/*

  16. ====================

  17. Total_time:117048s

  18. ====================

  19.  cum. time  percent           time_distribution(s)                     bytes_distribution(B)              uri_abs

  20.      38747   33.10%  %25<0.01 %50<0.03 %75<0.06 %100<2.82   %25<42 %50<61 %75<63 %100<155                 /api/record/getR

  21.      22092   18.87%  %25<0.02 %50<0.03 %75<0.06 %100<1.73   %25<34 %50<196 %75<221 %100<344               /api/getR/com/*/*/*

  22.      17959   15.34%  %25<0.15 %50<0.19 %75<0.55 %100<2.93   %25<2791 %50<3078 %75<3213 %100<11327         /api/getRInfo/com/*/*

透過上例可觀察指定時間內（預設當天0時至當前時間）hits/bytes/time三個維度的排名以及響應時間和響應大小的分佈情況。例如，看到某個uriabs只有比較少的hits確產生了比較大的bytes或耗費了較多的time，那麼該uriabs是否值得關註一下呢。

ip子命令

顯示基於ip地址的分析結果

  1. [ljk@demo ~]$ log_show.py api ip -l 2

  2. ====================

  3. From_cdn/Proxy:              hits  hits(%)       bytes  bytes(%)  time(%)

  4. ====================       199870    99.94   570.51 MB    99.99    99.99

  5.           Last_cdn_ip

  6.        xxx.57.xxx.189        1914     0.96   696.18 KB     0.12     0.68

  7.       xxx.206.xxx.154        1741     0.87     1.56 MB     0.27     0.98

  8.       User_ip_via_cdn

  9.        xxx.249.xxx.56         787     0.39   154.82 KB     0.03     0.23

  10.         xxx.60.xxx.86         183     0.09     1.05 MB     0.18     0.13

  11. ====================

  12. From_reverse_proxy:          hits  hits(%)       bytes  bytes(%)  time(%)

  13. ====================           66     0.03    68.83 KB     0.01     0.01

  14.     User_ip_via_proxy

  15.        xxx.188.xxx.21           2     0.00     1.53 KB     0.00     0.00

  16.           xxx.5.xxx.4           2     0.00    324.00 B     0.00     0.00

  17. ====================

  18. From_client_directly:        hits  hits(%)       bytes  bytes(%)  time(%)

  19. ====================           64     0.03     8.32 KB     0.00     0.00

  20.           Remote_addr

  21.         192.168.1.202          29     0.01     58.00 B     0.00     0.00

  22.         192.168.1.200          29     0.01     58.00 B     0.00     0.00

IP分析的思想是將請求按來源歸為三大類：Fromcdn/Proxy，Fromreverseproxy，Fromclient_directly，然後各自分類內按請求次數對IP地址進行排序

distribution 子命令

  1. 對 “所有request” 或 “指定uri/request_uri” 按 “分/十分/時/天” 為粒度進行聚合統計

  2. 對 “指定IP” 按 “分/十分/時/天” 為粒度進行聚合統計

適用場景：檢視request/IP隨時間在各聚合粒度內各項指標的變化情況，例如針對某個uri發現其請求數（或頻寬）變大，則可透過 distribution子命令觀察是某一段時間突然變大呢，還是比較平穩的變大

  1. # 示例1: 分析指定request的分佈情況, 指定按minute進行分組聚合, 預設顯示5行

  2. [ljk@demo ~]$ python log_show.py api request distribution "/view/*/*.json" -g minute                

  3. ====================

  4. uri_abs: /view/*/*.json

  5. Total_hits: 17130    Total_bytes: 23.92 MB

  6. ====================

  7.     minute        hits  hits(%)       bytes  bytes(%)           time_distribution(s)                     bytes_distribution(B)            

  8. 1803091654        1543    9.01%     2.15 MB     8.98%  %25<0.03 %50<0.03 %75<0.05 %100<1.07   %25<1532 %50<1593 %75<1645 %100<1982        

  9. 1803091655        1527    8.91%     2.13 MB     8.88%  %25<0.03 %50<0.04 %75<0.05 %100<1.04   %25<1538 %50<1592 %75<1642 %100<2143        

  10. 1803091656        1464    8.55%     2.05 MB     8.57%  %25<0.03 %50<0.04 %75<0.05 %100<1.03   %25<1536 %50<1592 %75<1642 %100<1952        

  11. 1803091657        1551    9.05%     2.15 MB     8.97%  %25<0.02 %50<0.03 %75<0.04 %100<0.89   %25<1534 %50<1594 %75<1639 %100<1977        

  12. 1803091658        1458    8.51%     2.06 MB     8.61%  %25<0.02 %50<0.03 %75<0.04 %100<2.35   %25<1540 %50<1596 %75<1644 %100<2146

透過上例，可展示"/view/*/*.json"在指定時間段內的分佈情況，包括hits/bytes/time總量以及每個粒度內個指標相對於總量的佔比；該子命令亦能展示各指標隨時間的“趨勢”。

說明： minute欄位為指定的聚合（group）粒度，1803091654 表示“18年03月09日16時54分”
可透過 -g引數指定聚合的粒度（minute/tenmin/hour/day）
distribution子命令後可以跟具體的uri/requesturi（顯示該uri/request_uri以指定粒度隨時間的分佈）或不跟uri（顯示所有請求以指定粒度隨時間的分佈）

  1. # 示例2: 分析指定IP產生的請求數/頻寬隨時間分佈情況, 預設聚合粒度為hour

  2. [ljk@demo ~]$ python log_show.py api ip -t 180314 distribution "140.206.109.174" -l 0

  3. ====================

  4. IP: 140.206.109.174

  5. Total_hits: 10999    Total_bytes: 4.83 MB

  6. ====================

  7.       hour        hits  hits(%)       bytes  bytes(%)

  8.   18031306        1273   11.57%   765.40 KB    15.47%

  9.   18031307        2133   19.39%  1004.74 KB    20.31%

  10.   18031308        2211   20.10%     1.00 MB    20.74%

  11.   18031309        2334   21.22%     1.05 MB    21.72%

  12.   18031310        2421   22.01%   850.79 KB    17.20%

  13.   18031311         627    5.70%   226.30 KB     4.57%

說明： hour欄位表示預設的聚合粒度，18031306表示“18年03月13日06時”
-l 0 表示不限制輸出行數（即輸出所有結果）

detail 子命令：

  1. 對某一uri進行詳細分析，檢視其不同引數（args）的各項指標分佈

  2. 對某一IP進行詳細分析，檢視其產生的請求在不同uri_abs間的分佈情

適用場景：比如定位到某一型別的uriabs在某方面（hits/bytes/time）有異常，就可以透過detail子命令對該類uriabs進行更近一步的分析，精確定位到是哪種引數（args_abs）導致的異常；或者觀察到某個IP訪問異常，可以再深入一下該IP是泛泛的訪問呢，還是隻對某些uri感興趣。

  1. # 示例1:

  2. [ljk@demo ~]$ python log_show.py api -f 180201 request detail "/recommend/update" -l 3

  3. ====================

  4. uri_abs: /recommend/batchUpdate

  5. Total_hits: 10069    Total_bytes: 7.62 MB

  6. ====================

  7.     hits  hits(%)      bytes  bytes(%)  time(%)           time_distribution(s)                   bytes_distribution(B)            args_abs

  8.     4568   45.37%    3.46 MB    45.44%   47.96%  %25<0.04 %50<0.06 %75<0.07 %100<0.47   %25<755 %50<795 %75<845 %100<1484         uid=*&category_id=*&channel=*&version=*

  9.     4333   43.03%    3.25 MB    42.64%   42.30%  %25<0.03 %50<0.05 %75<0.07 %100<0.48   %25<752 %50<791 %75<840 %100<1447         category_id=*&channel=*&uid=*&version=*

  10.      389    3.86%  314.15 KB     4.03%    0.88%  %25<0.02 %50<0.03 %75<0.04 %100<0.06   %25<766 %50<802 %75<850 %100<1203         category_id=*&channel=*&version=*

透過上例可觀察到"/recommend/update"這個uri所對應的不同引數各個指標的情況。另外還有一個附帶的發現：開發在書寫引數時相同的引陣列合沒有按同一個順序書寫，雖不影響功能，但在精準的進行應用效能監控的時候會造成一定困擾。

說明： detail子命令後跟隨uri（不含引數，含引數的話將忽略引數）

  1. # 示例2: 觀察某個IP分別產生了多少種請求, 每種請求的(hits/bytes/time)指標

  2. [ljk@demo ~]$ python log_show.py m -t 180314 ip detail "1.2.3.4"

  3. ====================

  4. IP: 140.206.109.174

  5. Total_hits: 10999    Total_bytes: 4.83 MB

  6. ====================

  7.     hits  hits(%)      bytes  bytes(%)  time(%)  uri_abs

  8.    10536   95.79%  405.47 KB     8.19%   92.01%  /introduction/watch

  9.      147    1.34%    1.90 MB    39.31%    1.93%  /view/*/*.html

  10.      138    1.25%  407.42 KB     8.23%    2.41%  /chapinfo/*/*.html

  11.       42    0.38%  644.88 KB    13.03%    1.38%  /info/*.html

  12.       30    0.27%  229.98 KB     4.65%    1.14%  /classify/*.json

loganalyse.py部署說明： 該指令碼的設計標的是將其放到web server的的計劃任務裡，定時（例如每30分鐘或10分鐘，自定義）執行，在需要時透過logshow.py進行分析即可。

  1. */15 * * * * export LANG=zh_CN.UTF-8;python3 /home/ljk/log_analyse.py &> /tmp/log_analyse.log

Note

  1. 其中 uri_abs和 args_abs是對uri和args進行抽象化（抽象出特定的請求樣式，即將請求分類看待）處理之後的結果，預設規則如下
    uri：將request_uri以"/"和"."分割為幾段，若某一段全部由數字組成則將其抽象為一個"*"  
    args：將所有的value替換成"*"  

  2. common/common.py中還有一些其他有趣的函式

本文作者

❈

jkklee，6年運維老司機一枚，擅長複雜場景下的故障排查，效能最佳化。目前比較側重於將自己這些年的運維積累轉化成通用易用的各種工具，希望能幫到更多的運維同胞。

本文專案GitHub地址，歡迎star和fork：

https://github.com/jkklee/web_log_analyse

❈

《Python人工智慧和全棧開發》2018年07月23日即將在北京開課，120天衝擊Python年薪30萬，改變速約~~~~

*宣告：推送內容及圖片來源於網路，部分內容會有所改動，版權歸原作者所有，如來源資訊有誤或侵犯權益，請聯絡我們刪除或授權事宜。


- END -


更多Python好文請點選【閱讀原文】哦

↓↓↓

贊(0)
標籤：

相關推薦

熱門標籤

iOS (11238)微軟 (4955)Linux (4274)安全 (4180)Python (4161)效能 (3165)運維 (2774)最佳化 (2419).NET (2262)Google (2136)機器學習 (1795)併發 (1613)分散式 (1559)叢集 (1240)SQL (1174)Mysql (1060)區塊鏈 (1017)Docker (977)微服務 (922)面試 (919)Apache (743)NLP (725)Redis (719)Android (668)Git (640)架構師 (632)Nginx (630)Facebook (599)JVM (595)爬蟲 (476)

熱門文章

分享創造快樂

© 2024 知識星球   網站地圖