知識星球導讀：在沒有核心繫統原始碼的情況下，修改原始碼列印耗時的方法無法使用，透過tcpdump、wireshark、gdb、010 editor、火焰圖、ida、資料庫抓sql耗時陳述句、oracle ash報告、loadrunner等工具找到了伺服器tps上不去，C程式行程隨機掛掉的問題，並順利解決，收穫頗多。
楊振，宜信工程師，前微博feed組工程師，對原始碼學習感興趣
董建，宜信工程師，前微博工程師，關註大資料和高可用技術
背景：
公司最近新上線一個系統，主要架構如下：
測試環境系統部署後，出現了兩個問題：
1. loadrunner壓測tps上不去，壓測java介面tps 單機只能到100多tps就上不去了，耗時從單次訪問的100ms上升到110併發時的1s左右。
2.壓測期間C伺服器1 經常不定時掛掉。
因為某些原因，該專案C相關程式沒有原始碼，只有安裝部署檔案，為瞭解決上述兩個問題，我們幾個同事和重慶同事一塊參與問題排查和解決。因為沒有原始碼，中間經歷了層層波折，經過一個月努力，終於解決了上述兩個問題，整個排查過程學到了很多知識。
用到的分析工具：
1.tcpdump,
2.wireshark,
3.gdb,
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);修改成了空指令，重新部署後沒再出現系統崩潰的問題。
