最近解決了個比較棘手的問題，由於排查過程挺有意思，於是就以此為素材寫出了本篇文章。
這是乙個偶發的效能問題。在每天幾百萬比交易請求中，平均耗時大約為300ms，但總有那麼100多筆會超過1s，讓我們業務耗時監控的99.99線變得很尷尬。如下圖所示:
為了精益求精,更為了消除這個尷尬的指標，筆者開始探尋起這100多慢請求筆的原因。
由於筆者寫的框架預留了traceid,所以找到這筆請求的整個呼叫的鏈路還是非常簡單的。 而且通過框架中的***在效能日誌中算出了每一筆請求的耗時。這樣，非常便於分析鏈路倒是是在哪邊耗時了。效能日誌中的某個例子如下圖所示:
2020-09-01 15:06:59.010 [abcdefg,a->b,dubbo-thread-1,ipa->ipb] b.facade,cost 10 ms我們從監控系統看出來正常的b系統呼叫c系統平均耗時只有20ms,這次的耗時增長了10倍！
正常思路，那當然是c系統有問題麼，畢竟慢了10倍！去c系統的效能日誌裡面看看,
2020-09-01 15:06:59.210 [abcdefg,b->c,dubbo-thread-1,ipb->ipc] c.facade,cost 20 ms由於筆者對tcp協議還是比較了解的，tcp第一次丟包重傳是200ms，那麼加上c處理的時間20ms,即220ms必須得大於200ms。而由於nagle和delayack造成的tcp延遲也僅僅是40ms,兩者相加60ms遠遠小於200ms,所以這個200ms是丟包或者delayack的概率不大。
本著萬一呢的態度,畢竟下絕對的判斷往往會被打臉，看了下我們的監控系統，發現當時流量距離網絡卡容量只有1/10左右，距離打滿網絡卡還有非常遠的距離。
注意，這個監控的是由kvm虛擬機器虛擬出來的網絡卡。 看了這個流量，筆者感覺網路上問題的概率不大。
筆者第二個想到的是gc了，但是觀察了b和c的當時時刻的gc日誌，非常正常，沒有fullgc，younggc也在毫秒級，完全不會有200ms這麼長。tcp重傳+雙方都younggc?這個也太巧了點吧，也不是不可用。不過詳細的計算了時間點，並納入了雙方機器的時鐘誤差後，發現基本不可能。
盡然這個問題每天有100多筆(當然了，也不排除其中混雜了其它不同的問題),那麼就試試看看其它幾筆，有沒有什麼共性。這一看，發現個奇怪的現象，就是有時候是a呼叫b慢，有時候是b呼叫c慢，還有時候是e呼叫f慢。他們唯一的共性就是耗時變長了，但是這個耗時增加的比例有5倍的，有10倍的，完全沒有規律可循。
這不禁讓筆者陷入了沉思。
既然通用規律只有變慢，暫時無法進一步挖掘。那麼還是去b系統上去看看情況吧，去對應b系統上故意不用grep而是用less看了下，上下掃了兩眼。突然發現，貌似緊鄰著的幾條請求都很慢，而且是無差別變慢！也就是說b系統呼叫任何系統在這個時間點都有好幾倍甚至十幾倍的耗時！
終於找到了乙個突破點，b系統本身或者其所屬的環境應該有問題！於是筆者用awk統計了下 b系統這個小時內每分鐘的平均呼叫時長，用了下面這條命令:
cat 效能日誌 | grep '時間點 | awk -f ' ' '' |.......| awk -f ' ' 'end}'所有呼叫慢的機器，都非常巧的在每個小時06-08分鐘之內呼叫慢。再觀察下慢的請求，發現他們也全部是分布在不同小時的06-08分時間段內！
這一看就發現規律了，原來變慢的機器上都和redis共宿主機！
登陸上對應的redis伺服器，發現cpu果然在那個時間點有尖峰。而這點尖峰對整個宿主機的cpu毫無影響(畢竟宿主機有64個核)。crontab -l 一下，果然有定時任務，指令碼名為backup!它起始時間點就是從06分開始往glusterfs盤進行備份，從06分開始cpu使用率開始上公升=>07分達到頂峰=>08分降下來，和耗時曲線完全一致！
原來redis往gluster盤備份佔據了大量的io操作，所以導致宿主機上的其它應用做io操作時會變得很慢，進而導致但凡是這個備份時間內系統間呼叫的平均耗時都會暴漲接近10倍，最終導致了高耗時的請求。
由於我們線上每個應用都有幾十台機器，而基本每次呼叫只有幾十毫秒。所以只有這個請求連續落到三個甚至多個和redis共宿主機的系統裡面才會導致請求超過1s，這樣才能被我們的統計指令碼監測到，而那些大量的正常請求完全拉平了平均值。
我們將線上實時鏈路的系統從對應有redis的宿主機中遷移出來，再也沒有那個尷尬的1s了。
網絡卡變慢 解Bug之路記一次線上請求偶爾變慢的排查
最近解決了個比較棘手的問題，由於排查過程挺有意思，於是就以此為素材寫出了本篇文章。這是乙個偶發的效能問題。在每天幾百萬比交易請求中，平均耗時大約為300ms，但總有那麼100多筆會超過1s，讓我們業務耗時監控的99.99線變得很尷尬。如下圖所示 為了精益求精,更為了消除這個尷尬的指標，筆者開始探尋起...
排查Mysql突然變慢的一次過程
自 嚴陣以待 目錄上週客戶說系統突然變得很慢，而且時不時的蹦出乙個404和500，弄得真的是很沒面子，而恰巧出問題的時候正在深圳出差，所以一直沒有時間 看問題，一直到今天，才算是把問題原因找到。剛開始得到是系統慢的反饋，沒有將問題點定位到資料庫上，查了半天服務是否正常 因為之前有一次dubbo記憶體...
記一次生產ORACLE資料庫突然查詢變慢
資料庫 oracle 有乙個流水表，表資料量千萬級，乙個管理臺常用條件分頁查詢突然變慢，有日期條件且有索引。部署伺服器是多台，資料庫查詢操作使用hibernate框架。逐台伺服器sql日誌跟蹤排查，根據hibernate發出sql語句，在oracle資料庫檢查對應的執行計畫，使用檢視 v sql 獲...