項目背景:Windows Server 2016 / Springboot / JDK1.8 / Oracle11.2.0
具體問題:項目在本地運行正常,接口返回時間都在幾十毫秒的級別,但是部署到服務器后部分接口返回時間甚至會達到六七秒。
排查過程:
首先懷疑網絡原因,F12查看請求后發現網絡傳輸時間可以忽略不計,排除之。
然后懷疑服務器壓力過大,查看內存和CPU負載都正常,也排除掉。
之后懷疑數據庫原因,使用本地項目連接服務器庫,一切正常,排除之。又想到可能是連接池配置有問題導致一直在等待獲取連接,確認並修改以后問題依然存在。
然后排除變量法,在另一台同樣系統及配置的服務器上部署一整套項目包括數據庫,同樣存在問題。
懷疑JVM配置有問題導致頻繁GC導致的運行變慢,經確認幾乎沒有FGC,YGC也並不頻繁。並且修改最大堆內存之后問題依舊。
懷疑JDK版本導致的不明bug,安裝了跟本地相同版本JDK以后,問題依舊。
多次重啟項目以后發現項目剛啟動的時候響應速度正常,運行一分鍾左右明顯開始變慢。
編寫一段測試代碼,單純for循環輸出10W個數字,本地運行毫秒級,但是服務器輸出卻花了將近2分鍾,同時觀察到運行過程中Java進程本身只占該進程所使用CPU的很小一部分,大部分被控制台所占用(服務器為12核,單核100%就是8%):
之后將控制台進程結束,問題解決。
總結:該問題是因為在Windows Server環境下,圖形化界面打印的控制台占用大量CPU導致(疑似bug?)。服務剛啟動的時候因為控制台內容不多,所以處理速度正常。采用服務方式啟動項目或者啟動后結束掉控制台進程即可解決。其實在確認CPU內存負載的時候就應該發現這個問題,但是當時腦抽沒想到顯示的百分比是占12個核,才導致了后續一堆的排查。