案例分享:巧用工具提高無源碼系統的性能和穩定

導讀:在沒有核心繫統源碼的狀況下,修改源碼打印耗時的方法沒法使用,經過tcpdump、wireshark、gdb、010 editor、火焰圖、ida、數據庫抓sql耗時語句、oracle ash報告、loadrunner等工具找到了服務器tps上不去、C程序進程隨機掛掉的問題,並順利解決,收穫頗多。java

背景

公司最近新上線一個系統,主要架構以下:sql

測試環境系統部署後,出現了兩個問題:數據庫

1.loadrunner壓測tps上不去,壓測java接口tps 單機只能到100多tps就上不去了,耗時從單次訪問的100ms上升到110併發時的1s左右。 2. 壓測期間C服務器1 常常不定時掛掉。tomcat

由於某些緣由,該項目C相關程序沒有源碼,只有安裝部署文件,爲了解決上述兩個問題,咱們幾個同事和重慶同事一塊參與問題排查和解決。由於沒有源碼,中間經歷了層層波折,通過一個月努力,終於解決了上述兩個問題,整個排查過程學到了不少知識。安全

用到的分析工具

1.tcpdump,性能優化

2.wireshark,服務器

3.gdb,session

4.010 editor,架構

5.火焰圖,併發

6.ida,

7.數據庫抓sql耗時語句,

8.oracle ash報告,

9.loadrunner

幾句話總結

1.C程序客戶端socket長鏈接調用C服務端存在性能瓶頸,經過tcpdump,wireshark 二進制分析出傳輸協議後改用java調用C服務端,單機tps提高1倍,性能提高3倍

2.數據庫語句存在for update 語句致使併發上不去,通過分析從業務上採用sequence 替換for update語句,並經過010 editor直接修改二進制 修改for update 語句相關邏輯爲sequence ,系統具有了擴容服務器tps也能同步提高的能力

3.數據庫insert語句併發狀況下存在瓶頸,擴大oracle redo log日誌大小解決,繼續提高tps40%。

4.程序進程隨機掛掉,經過gdb分析core dump文件,定位到在併發狀況下程序中使用的gethostbyname有問題,採用臨時方法解決。

分析過程

1.第一次瓶頸定位

剛開始排查問題時,loadrunner壓測java接口,併發用戶從0逐漸增長到110個的狀況下,tps到100左右就再也不提高,響應耗時從100ms增大到1s。此時咱們的分析重點是誰是當前的主要瓶頸

再看一遍架構圖, 圖中5個節點都有多是瓶頸點,數據庫此時咱們經過數據庫dba管理權限抓取耗時sql,沒抓取到,先排除數據庫問題,java的咱們打印分步耗時日誌,定位到jni調用 c客戶端耗時佔比最大。這時瓶頸點初步定位到C客戶端,C服務端1,C服務端2 這三個節點。

由於沒有源碼,咱們採用tcpdump抓包分析,在C服務器1上

tcpdump   -i  eth0  -s  0   -w aa.txt  host  java客戶端ip

抓出的包用wireshark分析

經過追蹤流-TCP流 分析服務端耗時並無變的太大,由於C客戶端和C服務端是長鏈接,多個請求可能會共用一個鏈接,因此此時分析出的數據可能會不太準,所以咱們採用loadrunner壓測,其它條件不變,一臺C服務器1和兩臺C服務器1分別查看耗時變化,

其它條件不變,一臺java服務器和兩臺java服務器分別查看耗時變化.

最終定位到是C客戶端的問題。(ps:在wireshark的分析數據時還跟秦迪大師弄明白了tcp延遲確認)

2.改造C客戶端

C客戶端和C服務端是經過長鏈接通訊的,直接改造C代碼難度較大,全部咱們準備把C替換成java,這就須要分析C之間通訊傳參時候用的什麼協議,而後根據這個協議用java重寫。咱們根據以前的經驗推測出了編碼協議,用wireshark分析二進制確認確實是這種編碼。

咱們根據這種協議編碼採用java重寫後,一樣在110併發用戶狀況下,tps提高到了210(提高兩倍),耗時降到了330ms(是原來的三分之一)

3.第二次瓶頸定位。

通過第二步優化後tps提高了兩倍,可是此時擴容tomcat,擴容C服務器,tps就維持在210左右,不會變高了。所以咱們繼續進行定位新的瓶頸點。此時找dba要到一個實時查看oracle 耗時sql的語句

select

(select b.SQL_TEXT from v$sqlarea b where b.SQL_ID=a.SQL_ID ) sqltxt,

(select c.SQL_FULLTEXT from v$sqlarea c where c.SQL_ID=a.SQL_ID ) sqlfulltxt,

a.username, a.LAST_CALL_ET,a.MACHINE ,a.command, a.EVENT, a.SQL_ID ,a.SID,a.SERIAL#,

'alter system kill session ''' || a.SID ||','||a.SERIAL# ||''';' as killstment

from v$session a

where a.STATUS = 'ACTIVE'

and a.USERNAME not in ('SYS', 'SYSTEM')

order by

a.LAST_CALL_ET desc ,a.username,a.MACHINE ,a.command, a.EVENT,  a.SQL_ID ,a.SID;

發現有個for update的sql 併發量大的時候部分請求 LAST_CALL_ET列的值能達到6秒,for update致使了全部請求被串行執行,影響了併發能力。咱們通過分析業務邏輯後,用sequence暫時替換 for update 語句,可是咱們沒有源碼,無法修改,後來又經過010 editor 直接修改二進制文件,經過010 editor 查詢找到了 for update 語句,順利替換。

替換後,4臺C服務器tps達到了580,提高了2.7倍(580/210),系統初步具有了橫向擴展能力

4.第三次瓶頸定位。

通過上一步改造,4臺C服務器時系統的tps提高了2.7倍,可是並無提高到4倍(210*4=840),沒有線性提高,說明仍是有別的瓶頸,又經過dba上邊給的sql發現insert 語句偶爾耗時也很長,在1s左右,EVENT等待事件是IO事件,DBA同事給修改了redo log file 大小(這個是測試環境Oracle,以前沒有優化),從默認的50M,修改成1G, tps 提高到了640 (還沒提高到4倍,也就是說還有瓶頸,可能仍是數據庫,但由於數據庫暫時沒辦法抓取到毫秒級的耗時sql,沒再繼續追查)

通過這幾回性能提高,加上咱們測試服務器配置都不高,若是線上服務器性能預估能達到1000tps,基本知足眼前需求,所以就沒再繼續進行性能優化。

5.程序進程隨機掛掉問題。

壓測過程當中,C服務器進程常常隨機掛掉,經過tail -f /var/log/messages 發現生成了core dump 文件,可是又被系統自動刪除了。董建查到了開啓core dupm文件的方法,以下:

a、ulimit -c

查看是否爲0,若是爲0,表示coredump文件設置爲0,須要修改成不限制

ulimit -c unlimited

b、修改/etc/abrt/abrt-action-save-package-data.conf

ProcessUnpackaged = yes

修改後進程又崩潰時core dump 文件生成了,進入core dump 目錄進行調試

gdb 腳本路徑 coredump

bt 顯示堆棧信息

繼續執行以下命令

f 0

set print pretty on

info local        //顯示當前函數中的局部變量信息。

經過p命令查看裏邊變量的值

發現變量thishost->h_addr_list的值爲null

咱們分析多是併發請求時有方法不是線程安全的致使這個值爲null,從而引發了進程crash,繼續調試。

在gdb中 set logging on 把調試信息輸出到文件

thread apply all bt 輸出全部的線程信息。

退出gdb

grep --color -i clientconnect -C5 gdb.txt

確實有兩個線程併發在訪問

經過ida工具反編譯so,最終定位到如下語句在併發時有問題,thishost中的變量可能會被另外一個線程在一瞬間初始化爲null。

thishost = gethostbyname((const char *)hostname);

ip = inet_ntoa(*(struct in_addr *)*thishost->h_addr_list);

根據咱們的項目特色,由於咱們沒有遠程調用,C服務端1和C服務端2都部署在了同一臺服務器上,因此咱們經過修改二進制把地址暫時寫死成了127.0.0.1,把ip = inet_ntoa(*(struct in_addr *)*thishost->h_addr_list);修改爲了空指令,從新部署後沒再出現系統崩潰的問題。

做者簡介:楊振-宜信工程師,前微博feed組工程師,對源碼學習感興趣;董建-宜信工程師,前微博工程師,關注大數據和高可用技術 原文發佈於 高可用架構

來源:宜信技術學院

相關文章
相關標籤/搜索