之前寫過一篇文章,https://www.cnblogs.com/qidian10/p/6028784.html 解釋如何解決此類問題,但現在回過頭來想一下,之前的文章還是太過淺顯,無法完全有效的徹底解決此類問題。
近期因為工作原因,這個問題又凸顯出來,這里做下解決思路,通過如下的解決思路基本可以應對任何此類這樣的問題,能夠快速准確的定位原因。
一、事發背景
謀SaaS架構產品,基於.net framework 跑在iis上,負載均衡3台web;
情況是每天的非固定時間會報一次cpu 100%的警告,部分情況下可在1分鍾左右的時間自動恢復;訪問量大的情況下持續很久需要人工干預;直觀的表現如下:
1)cpu瞬間打滿
2)iis請求隊列排隊嚴重
3)附加着帶來若干redis請求異常,部分第三方api請求異常等
4)總之客戶怨聲載道,給系統打上“卡”的標簽,投訴不斷
二、分析問題
由於系統不是經常性的卡頓,是偶發性的,基本定性為幾個方向:
1、某一個不是特別常用的請求觸發,或者某一個不是經常能夠被操作的功能點,觸發導致的;
2、redis請求堵塞導致:這個最先排除,因為卡頓的時候,其他負載組的並不卡;
3、最后一張圖的直觀反饋是session阻塞
由於歷史原因,系統保留了部分session的代碼,根據資料顯示,大並發情況下請求同一個session,利用session默認管理器的時候會導致請求排隊。
https://stackoverflow.com/questions/16570855/requests-hanging-on-session-module-on-iis-7-5/27481000#27481000
https://blog.csdn.net/anyi2404/article/details/102251579
花了一個晚上時間,把系統里所有帶session的引用全部重構掉,上線生產后,但是問題依舊
那么只有第一個可能了,按照這個思路排查這個期間發生的所有請求,按照每個請求的參數等情況去模擬,是可以復現問題的,但是這個工作量大的驚人,卡頓期間的url請求是幾乎千條記錄,靠人工是不現實的,另一主要原因是即使通過該方法解決了本問題,也不可以復制解決方案去應對未來的問題。所以這個方案放棄掉了。
三、開始抓dump分析
按照以往的慣例,每次卡頓的時候只需要在任務管理器進程-右鍵轉存儲,即可獲取到dump文件,然后分析問題即可;但是該方式有個“坑”就是你抓取dump的時候不能存在應用程序池重啟的情況,必須保證都是同一個應用程序池進程,否則的話你可能無法分析到真正的原因。
所以通過人工的方式抓取存在一定的運氣性,常規類的一般都可以解決。但這次我們事后分析恰好踩了這次的坑,每次分析dump,幾乎都是常規類的請求,代碼復盤上基本不會有性能問題。
四、如何抓取到正確的dump包(工具一)
利用procdump:https://docs.microsoft.com/en-us/sysinternals/downloads/procdump 基本命令如下
procdump -ma -s 5 -n 2 -c 70 2160
定義:當-c 70 cpu超過70%的時候,連續超過-s 5秒的時候,抓取-n 2個dump,該操作綁定進程2160
利用工具抓取可以有效避免dump不准確的問題,執行上述命令后,服務器會自動開啟監控任務,一單觸發,自動打包dump文件
五、分析dump
之前寫過一份簡易版本的分析方案:http://www.cnunify.com/help/helpDetail?id=6abdffd4-c4c6-4310-ac02-32d62e7e62a7&title=%E7%9F%A5%E8%AF%86%E5%BA%93
更全面的可以參考園子大佬的:https://www.cnblogs.com/huangxincheng/category/1967355.html
毫無疑問大量的請求在等待被執行,正在隊列中的還有283,足以讓cpu高起來,那么接下來就看,到底是什么原因導致請求堵塞了。
經過不斷的抓包分析,最終根據請求cpu占用時間排序靠前的線程,定位到一個方法BulkInsert(當然804個請求隊列里面還有很多個其他類型的方法請求,需要專業,也需要運氣)
之前沒有特別注意這個方法,認為就是一個普通的批量插入,而且本地執行的時候也會很快,經過各種反復猜想后,最后突然想起一個問題:
因為EF自身的問題,批量插入、更新等效率太低,所以替換了一個第三方組件來支持:Z.EntityFramework.Extensions,這個組件有一個毛病,就是預熱的時候會非常慢,必須等待預熱完成才可以正常執行,預熱期間的請求都會排隊等待。
講人話就是:第一次調用BulkInsert方法,會觸發預熱,會非常慢(看你實體模型數量),之后就正常毫秒級別了。
那么是什么原因會導致Z.EntityFramework.Extensions預熱呢?
只有一個可能就是這個期間發生了應用程序池的重啟,某些原因導致了異常,觸發了重啟。
恍然大悟,之前分析的時候就注意到was進程會崩潰,並報錯“為應用程序池“XXX”提供服務的進程在與 Windows Process Activation Service 通信時出現嚴重錯誤。該進程 ID 為“XXXX”。數據字段包含錯誤號”
六、確認邏輯
到目前為止,基本定性了問題原因:某些請求,導致was(w3pw.exe)崩潰,進而應用程序池重啟,重啟觸發了Z.EntityFramework.Extensions預熱,預熱過程帶來了所有請求排隊,訪問量越高,阻塞越長,嚴重情況下服務器可能整體宕機!
七、究其根本,解決問題
兩個方式:要么替換Z.EntityFramework.Extensions組件,但治標不治本;要么找到真正觸發w3pw.exe崩潰和應用程序池重啟的代碼;很顯然必須究其根本。
八、如何抓取到正確的dump包(工具二)
本塊是文章重點,如何在異常情況下抓到最正確的dump包是分析問題的關鍵,上面介紹了一種抓dump方式,但是應對應用程序池崩潰問題,procdump工具並不奏效!
此處必須祭出大殺器:DebugDiaog2.0,實際只需要這一個工具即可。https://www.microsoft.com/en-us/download/details.aspx?id=49924
微軟官方的參考demo:https://docs.microsoft.com/en-us/iis/troubleshoot/performance-issues/troubleshooting-high-cpu-in-an-iis-7x-application-pool
中文翻譯版:https://cloud.tencent.com/developer/article/1619150?from=15425
基本按照文章的內容照做即可抓到正確的dump包。
DebugDiaog提供了當cpu、內存等資源異常時候自動監控和抓dump,也提供了當應用程序crash的時候自動抓dump。
按照對應操作步驟去創建規則rule即可
性能的抓包參考:https://docs.microsoft.com/en-us/iis/troubleshoot/performance-issues/troubleshooting-high-cpu-in-an-iis-7x-application-pool
crash抓包參考:https://stackoverflow.com/questions/18335678/how-to-debug-w3wp-clr-dll-error?noredirect=1
crash抓包的時候注意里面有個步驟需要選擇類型,比如是棧溢出,還是其他異常,這個信息來自
九、現出原形
利用第八步驟,抓到合適dump之后,即可正常分析問題了,也沒必要用windbg分析了,直接用debugdiag自帶的分析器,掛上去分析
結果:
至此罪魁禍首已經定位,找相關人員處理掉即可。
十、能學到點什么,總結精髓
1、dump是什么
2、如何抓取普通的dump,工具procdump
3、如何抓取特殊異常情況下最正確的dump,工具debugdiag,這是最重要的一步
4、如何分析dump內容,!t、!tp、.cordll -lp <path>、!runaway、!~[thread]s、!clrstack等等
5、Z.EntityFramework.Extensions的坑不得不重視
參考文獻:
https://stackoverflow.com/questions/18335678/how-to-debug-w3wp-clr-dll-error?noredirect=1