使用Python簡單分析JSON日志

1.問題起因

最近工作中遇到個問題,開始是凌晨的一段時間锣咒,線上業(yè)務(wù)頻繁報(bào)警红符,后來查詢CAT和日志,發(fā)現(xiàn)是由于一個名為selectByOrderId的慢查詢導(dǎo)致的冰评。



遇到這種情況映胁,通常會想到加索引。但是查看數(shù)據(jù)了解業(yè)務(wù)之后集索,發(fā)現(xiàn)這張300W數(shù)據(jù)表中只有幾十條該字段非空屿愚,且會較頻繁更新汇跨。于是想進(jìn)一步分析务荆,看看有什么其他的解決方案。
再看long-url穷遂,有一個用于客戶端上報(bào)支付結(jié)果的report接口占比非常大函匕。

數(shù)量上差不多,會不會有什么聯(lián)系呢蚪黑?翻了翻代碼盅惜,發(fā)現(xiàn)report接口的處理邏輯確實(shí)有調(diào)用selectByOrderId相關(guān)rpc的代碼,從這兩張圖來看忌穿,selectByOrderId慢查詢仿佛大部分是由report接口導(dǎo)致的抒寂,但是什么樣的參數(shù)會導(dǎo)致慢查詢還需要進(jìn)一步分析。
正好最近有點(diǎn)迷機(jī)器學(xué)習(xí)掠剑,學(xué)了點(diǎn)Python數(shù)據(jù)分析的皮毛屈芜,就用這個練練手吧。

2.著手調(diào)查

2.1 目標(biāo)

找到report接口響應(yīng)時間過長的共性

2.2 數(shù)據(jù)準(zhǔn)備

在服務(wù)器上拉取了包含report接口的api日志朴译,日志格式為"$requestId $json"井佑,在json格式中存儲了接口名稱、輸入?yún)?shù)眠寿、輸出參數(shù)躬翁、狀態(tài)碼、發(fā)起時間盯拱、耗時盒发、用戶設(shè)備等40多項(xiàng)信息,并且有多層嵌套狡逢。
使用awk迹辐、sed將數(shù)據(jù)提取成json數(shù)組的形式:

# 刪除requestId并使用在行尾添加,分割json串。由于json中可能有空格甚侣,所以使用截取字符串進(jìn)行提取明吩。
grep report api.log | awk '{print substr($0,27)}' | sed 's/$/,/' > report.json```
之后使用vim在文本開頭添加"["結(jié)尾添加"]"。(如果您有更好的方式可以告訴我哈)
至此json數(shù)組文件構(gòu)造完畢殷费。
將文件通過sz或scp下載到待分析的機(jī)器上印荔。

### 2.3 數(shù)據(jù)處理與分析
我使用備受推薦的Anaconda作為Python數(shù)據(jù)分析平臺低葫。Anaconda的依賴管理(包括python的版本)、已集成的常用庫仍律、集成Jupyter Notebook等常用數(shù)據(jù)分析工具嘿悬,用起來都非常方便。當(dāng)然Anaconda也不是必須的水泉,直接使用conda或pip善涨、easy_install安裝管理依賴也是沒問題的。
先簡單介紹下使用到的Python庫草则。
- pandas
高性能钢拧、簡單易用的數(shù)據(jù)結(jié)構(gòu)和數(shù)據(jù)分析工具。[10 minutes to Pandas](http://pandas.pydata.org/pandas-docs/stable/10min.html)
- numpy 
雖然沒有直接用到炕横,但它是pandas的基礎(chǔ)源内,由C語言開發(fā)。

打開Jupyter Notebook份殿,開始工作膜钓。
首先讀取json數(shù)據(jù),獲得DataFrame卿嘲。注意打開帶有utf-8編碼的文件用codecs.open代替open颂斜;因?yàn)閿?shù)據(jù)時帶有嵌套結(jié)構(gòu)的json,所以使用pd.io.json.json_normalize對數(shù)據(jù)標(biāo)準(zhǔn)化拾枣,類似{"p":{"id":5}}的節(jié)點(diǎn)會被解析為p.id=5沃疮,否則會解析成p="{"id":5}"。如果json中不含嵌套結(jié)構(gòu)放前,或者不使用嵌套數(shù)據(jù)忿磅,可以直接使用`df = pd.read_json(path)`得到DataFrame。
``` python
import pandas as pd
import codecs
import json

path = 'report.json'

with codecs.open(path, 'r', 'utf-8') as json_data:
    json_dicts = json.load(json_data) # 讀取json數(shù)據(jù)為list[dict]結(jié)構(gòu)
    json_df = pd.io.json.json_normalize(json_dicts)  # 處理嵌套json
    df = pd.DataFrame(json_df)
df.head()

通常原始數(shù)據(jù)需要進(jìn)行處理后才能使用凭语,比如去掉無關(guān)列葱她、處理空值、轉(zhuǎn)換列值似扔、新增列等吨些。
通過df.columns獲取列名后,可以通過easy_df = df.drop(['col1','col2'], axis=1, inplace=False)刪除某幾列炒辉,axis表示刪除的是列豪墅,inplace表示是否在原df中刪除。
下面針對ct列也就是接口耗時做統(tǒng)計(jì)匯總:
easy_df.describe(percentiles=[.50,.75,.90,.95])[['ct']]
describe()進(jìn)行快速統(tǒng)計(jì)匯總黔寇,percentiles可以添加多個百分位數(shù)進(jìn)行統(tǒng)計(jì)偶器,后面的[['ct']]表示只取ct列的匯總。

優(yōu)化前快速統(tǒng)計(jì).png

可以發(fā)現(xiàn),90%以上的請求耗時都很短屏轰,在80毫秒內(nèi)颊郎。但是由于小于10%的請求導(dǎo)致平均響應(yīng)時間(mean)接近一秒。那什么樣的請求耗時那么長呢霎苗?沒有什么頭緒姆吭,那就先比較下慢請求的部分和總體請求統(tǒng)計(jì)上有什么差別吧。

# 刪選耗時大于1秒的值
slow_df = easy_df[( easy_df.ct > 1000 )]```
進(jìn)行比較:

![image.png](http://upload-images.jianshu.io/upload_images/931112-18fe4690292ee286.png?imageMogr2/auto-orient/strip%7CimageView2/2/w/1240)
可以發(fā)現(xiàn)慢請求的一個共性就是參數(shù)值都是1.0唁盏。
## 3.得出結(jié)論
再翻代碼内狸,1代表著用戶的支付成功,當(dāng)上報(bào)接口的參數(shù)為1時厘擂,會進(jìn)行訂單查詢操作昆淡,會通過訂單號查詢代金券信息,也就是調(diào)用包含上面selectByOrderId的RPC驴党。但是由于沒有判斷該筆訂單是否有代金券支付瘪撇,導(dǎo)致了很多不必要的查詢获茬,而應(yīng)該查詢的那部分僅是一小部分港庄,且有緩存命中會直接返回。程序上的修改只需增加判斷恕曲,當(dāng)該筆訂單有代金券支付鹏氧,才調(diào)用RPC查詢即可。
## 4.小結(jié)
通過分析數(shù)據(jù)佩谣,推測數(shù)據(jù)之間的關(guān)聯(lián)性并驗(yàn)證把还,還是很有意思的。
學(xué)習(xí)機(jī)器學(xué)習(xí)的路還很漫長茸俭,要求的學(xué)科知識都是我非常欠缺的吊履,尤其是數(shù)據(jù)處理,以及背后的數(shù)學(xué)邏輯调鬓。能把學(xué)到的一點(diǎn)皮毛用到工作和生活中來學(xué)以致用艇炎,一直是我希望的。


最后編輯于
?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請聯(lián)系作者
  • 序言:七十年代末腾窝,一起剝皮案震驚了整個濱河市缀踪,隨后出現(xiàn)的幾起案子,更是在濱河造成了極大的恐慌虹脯,老刑警劉巖驴娃,帶你破解...
    沈念sama閱讀 221,198評論 6 514
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件,死亡現(xiàn)場離奇詭異循集,居然都是意外死亡唇敞,警方通過查閱死者的電腦和手機(jī),發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 94,334評論 3 398
  • 文/潘曉璐 我一進(jìn)店門,熙熙樓的掌柜王于貴愁眉苦臉地迎上來疆柔,“玉大人蕉世,你說我怎么就攤上這事∑庞玻” “怎么了狠轻?”我有些...
    開封第一講書人閱讀 167,643評論 0 360
  • 文/不壞的土叔 我叫張陵,是天一觀的道長彬犯。 經(jīng)常有香客問我向楼,道長,這世上最難降的妖魔是什么谐区? 我笑而不...
    開封第一講書人閱讀 59,495評論 1 296
  • 正文 為了忘掉前任湖蜕,我火速辦了婚禮,結(jié)果婚禮上宋列,老公的妹妹穿的比我還像新娘昭抒。我一直安慰自己,他們只是感情好炼杖,可當(dāng)我...
    茶點(diǎn)故事閱讀 68,502評論 6 397
  • 文/花漫 我一把揭開白布灭返。 她就那樣靜靜地躺著,像睡著了一般坤邪。 火紅的嫁衣襯著肌膚如雪熙含。 梳的紋絲不亂的頭發(fā)上,一...
    開封第一講書人閱讀 52,156評論 1 308
  • 那天艇纺,我揣著相機(jī)與錄音怎静,去河邊找鬼。 笑死黔衡,一個胖子當(dāng)著我的面吹牛蚓聘,可吹牛的內(nèi)容都是我干的。 我是一名探鬼主播盟劫,決...
    沈念sama閱讀 40,743評論 3 421
  • 文/蒼蘭香墨 我猛地睜開眼夜牡,長吁一口氣:“原來是場噩夢啊……” “哼!你這毒婦竟也來了捞高?” 一聲冷哼從身側(cè)響起氯材,我...
    開封第一講書人閱讀 39,659評論 0 276
  • 序言:老撾萬榮一對情侶失蹤,失蹤者是張志新(化名)和其女友劉穎硝岗,沒想到半個月后氢哮,有當(dāng)?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體,經(jīng)...
    沈念sama閱讀 46,200評論 1 319
  • 正文 獨(dú)居荒郊野嶺守林人離奇死亡型檀,尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 38,282評論 3 340
  • 正文 我和宋清朗相戀三年冗尤,在試婚紗的時候發(fā)現(xiàn)自己被綠了。 大學(xué)時的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片。...
    茶點(diǎn)故事閱讀 40,424評論 1 352
  • 序言:一個原本活蹦亂跳的男人離奇死亡裂七,死狀恐怖皆看,靈堂內(nèi)的尸體忽然破棺而出,到底是詐尸還是另有隱情背零,我是刑警寧澤腰吟,帶...
    沈念sama閱讀 36,107評論 5 349
  • 正文 年R本政府宣布,位于F島的核電站徙瓶,受9級特大地震影響毛雇,放射性物質(zhì)發(fā)生泄漏。R本人自食惡果不足惜侦镇,卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 41,789評論 3 333
  • 文/蒙蒙 一灵疮、第九天 我趴在偏房一處隱蔽的房頂上張望。 院中可真熱鬧壳繁,春花似錦震捣、人聲如沸。這莊子的主人今日做“春日...
    開封第一講書人閱讀 32,264評論 0 23
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽。三九已至剩胁,卻和暖如春诉植,著一層夾襖步出監(jiān)牢的瞬間祥国,已是汗流浹背昵观。 一陣腳步聲響...
    開封第一講書人閱讀 33,390評論 1 271
  • 我被黑心中介騙來泰國打工, 沒想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留舌稀,地道東北人啊犬。 一個月前我還...
    沈念sama閱讀 48,798評論 3 376
  • 正文 我出身青樓,卻偏偏與公主長得像壁查,于是被迫代替她去往敵國和親觉至。 傳聞我的和親對象是個殘疾皇子,可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 45,435評論 2 359

推薦閱讀更多精彩內(nèi)容