案例分析：
某系統的應用支持人員反饋，文件傳輸服務14029端口異常，業務被堵塞。我們登入系統檢查，除文件傳輸服務交易處理緩慢，其他類型的交易均未受影響，也就是說該服務器有多個對外服務端口，只有壹個端口異常。與應用開發人員溝通過後，反饋應用沒有實施過變更。同時應用開發人員反映這類業務全部是從公網接入的，我們登入F5設備，將公網接入業務漸出後，交易並發請求量下降，文件傳輸服務端口堵塞現象逐漸緩解，但從F5重新漸入公網業務後，問題重現。
從異常時收集的數據分析，14029服務端口約有3000個連接，其中大多數連接處於CLOSE_WAIT和LAST_ACK狀態。這麽多的CLOSE_WAIT和LAST_ACK說明通訊階段肯定不正常，看到這裏，大家都懷疑問題出現網絡層面了吧，這裏先不回答，先結合上面介紹的TCP原理中的CLOSE_WAIT和LAST_ACK思考壹下，現在問題僅反映出大量CLOSE_WAIT和LAST_ACK，連接建立階段未出現異常，說明什麽呢？繼續查看網絡通訊報文。異常時段的網絡報文如下：
從網絡報文看，連接釋放前大致正常，為什麽說大致正常，client和server有來有往，也無重傳等異常現象，但是，交互壹次經常有20多秒，所以只能說大致正常。在壹筆交易完成後，開始斷開連接，問題出現了，client端發出了FIN包，server立刻回復ACK，然後經過20多秒的等待後，又發送了長度為7的數據，再回復了FIN包，然後出現網絡重傳FIN包。
對於網絡重傳，乍壹看以為是網絡通訊丟包，但仔細壹推敲，其他時間不丟包，為什麽只在連接釋放階段丟包，沒有道理啊。就此，我們和網絡技術專家進行了溝通，得到的答復是：在通訊階段，大量客戶端超時發出連接關閉請求,也就是client發出了FIN包，server端服務進程處理超時未能及時響應關閉連接請求，超過10秒觸發防火墻安全保護機制，連接關閉應答包（FIN）被防火墻拋棄，以至於出現大量FIN包重傳的現象。答復就是說網絡沒問題，是應用程序超時了。
網絡丟包問題排除了，那麽問題可能就出在了應用程序上了，但應用程序的問題在哪裏呢？我們回顧了前面的整個分析過程，有兩個疑點和應用相關，壹是通訊報文中客戶端和服務端兩端交互延時很大，經常出現20多秒時差；二是大量客戶端發出斷鏈請求。帶著疑問，我們和應用開發人員進行溝通，進壹步了解了交易的整個流程，很快第二個疑點就明確了，正常情況下，交易都是由農行端關閉，不會由公網客戶端關閉，除非交易超時，從現象上看肯定出現了大量的客戶端交易超時。同時從應用開發人員提供的交易流程分析，每壹筆交易，分8次輸出日誌，也就是說壹筆交易記錄8次日誌，對日誌文件操作了8次。既然應用分步記錄日誌，那日誌肯定能反映交易每壹步的時間差，也就是說交易超時應用日誌中能直接看出來。打開日誌文件，發現日誌文件中幾乎很難看壹筆完整的、順序的日誌，這是由於應用進程池多個進程並行寫日誌所致。這麽重要的線索，怎麽能隨便放棄。為此我們根據日誌中的時間戳以及進程號的規律專門編寫了壹個腳本負責遍歷和排序近壹周的應用日誌，幾個小時後，令人振奮的結果出來了，排序後的日誌對每壹筆交易時間記錄很詳細，大多數時間，每壹筆交易都在壹秒內完成，壹到交易高峰，交易時間開始延遲，短的延遲2~3秒，長的延遲幾十秒甚至上百秒，從日誌可以推斷出這個問題壹直存在，只是反映出來程度輕重不同而已。
分析到這壹步，應該是明確了應用程序存在問題，但應用程序的問題究竟是什麽呢？有了方向，我們在業務高峰針對應用進程開啟了truss跟蹤，truss對交易的過程和底層調用非常詳細記錄如下：
交易中***有8次對於該日誌的寫入，以其中壹次日誌文件操作過程（kopen-kwrite-close）為例，其耗時達到1.1s以上。壹筆交易完成，時間基本耗費都在10多秒。同時段，還有其他多個14029端口相關進程對於此日誌並發操作，引起整筆中絕大多數都在進行該日誌文件操作。從Truss信息中可以看到交易打開日誌還是采用同步方式。
35782920: 48955803: 0.1007: kfork() = 18874542
18874542: kfork() (returning as child ...) = 0
18874542: 31785117: 0.1086: _getpid() = 18874542
35782920: 48955803: 0.1088: semget(1674622889, 1, 0)18874542: 31785117: 0.1088: thread_setmystate(0x00000000, 0x2FF21920) = 300942464 = 0
18874542: 31785117: 0.1091: _thread_self() = 31785117
18874542: 31785117: 0.1094: thread_setmystate(0x2FF21608, 0x2FF21910) = 0
18874542: 31785117: 0.1096: thread_setmymask_fast(0x00000000, 0x00000000, 0x00000000, 0xD051C880, 0x00000000, 0x11E5009D, 0x11E5009D, 0xF0256118) = 0x0000
0000
18874542: 31785117: 0.1104: thread_unlock(0x2003F750) = 0
18874542: 31785117: 8.0003: kopen("/ho22938062: 44761355: 8.0009: kopen("/home/beics/log/Fil = 83997862: 75104323: 8.0018: kopen
= 0 = 8 = 917170888: 63897901: 8.0034: close(9)16849568808: 53805667: 8.0037: kopen("/home/beics/log/FileSvr.20140604", O_RDWR|O_SYNC|O_APPE
= 0 = 9 = 932965182: 51970655: 8.0039: kopen("/home/beics/log/FileSvr.20140604", O_RDWR|O_SYNC|O_APPEND)35521118: 45220353: 8.0065: kopen("/home/b
eics/log/FileSvr.20140604", O_RDWR|O_SYNC|O_APPEND) = 8 = 98454202: 21954581: 8.0049: kopen("/home/beics/log/FileSvr.20140604", O_RDWR|O_SYNC|O_APPEND) = 91
5991212: 14877101: 8.0080: _erecv(7, 0x2FF21630, 7, 256, 0x00000000) = 76488658: 81134209: kwrite(8, 0x2FF208C4, 56) = 56
18874542: 31785117: kwrite(8, 0x2FF20B14, 53) = 53
18874542: [ 1 6 : 2 3 : 0 4 | 0 0 1 8 8 7 4 5 4 2 | ] [ 1 0 . *
18874542: . *. * ] ?: Q U I T\n
分析到這裏，相信大家知道怎麽回事了，truss中多個線程並行操作，時間延遲了，信息都是亂的。所以，經過最終分析結論如下：由於交易過於頻繁的、且使用同步方式對壹個日誌文件進行打開和寫入操作，而這些文件操作都是串行操作，交易之間相互競爭記錄日誌，導致交易處理時間延長、處理效率下降。至於異常時系統層面看到的大量CLOSE_WAIT 和LAST_ACK，應該比較好理解，由於交易進程處理變慢，服務端接收到客戶端發出的FIN包仍然在發送數據（響應前面的請求）所致，所以能看到很多CLOSE_WAIT；而LAST_ACK狀態，是由於交易超時情況下，觸發了防火墻安全機制，服務端回復的FIN被丟棄所致。
解決方案及建議：
應用開發人員在我們的建議下，對應用程序進行了優化，將打開文件方式改成異步方式，並改進了日誌記錄方法，每筆交易分步記入日誌改成先緩沖、交易完成後壹次性記入日誌文件方式，降低操作日誌文件的頻率，減少文件操作競爭。優化完成後，該問題徹底解決。
socket通訊異常問題排查和處置難度大，系統層和應用層都也難以快速進行應急處置。建議架構上盡量采用集群模式，實現應用負載均衡，有效地規避應用"單點"風險，提升應用的高可用性。
對於自行開發的socket通訊系統，應用與TCP通訊關聯緊密，異常處理機制都依賴應用實現，要詳盡考慮外部環境的各種復雜異常情況，確實是非常困難的事情，就如壹些業內經驗豐富開發人員所說的，標準的socket通訊程序，3分功能代碼，7分異常處置，如果缺乏這份決心，建議還是采用比較成熟的通訊中間件產品來實現通訊處理。