一次介面效能優化實戰
阿新 • • 發佈:2019-12-31
背景
系統前期設計不太合理,經常被使用者吐槽系統慢,而且預計雙十一雙十二期間系統的訪問量會飆升,所以系統的壓測和優化勢在必行
本次主要挑選首頁的介面來分析
應用配置
2核4G,邏輯CPU40
應用啟動2G記憶體
新生代老年代預設1:2
新生代GC收集器為parNew,老年代為CMS
優化前
壓測資料
執行緒數 | 平均耗時 | 總呼叫次數 | 異常次數 | 平均吞吐量 |
---|---|---|---|---|
120 | 1022 | 19822 | 8 | 107.2/S |
為什麼吞吐量會這麼低呢?
通過jvisual發現系統的CPU使用只有3%左右,但是記憶體在1-2秒的時間內就會達到峰值然後觸發GC
為什麼GC會如此頻繁? 初步猜想應該有大物件佔用著,GC一直回收不了
通過 jmap -histo pid 命令檢視可知字元型別陣列在程式執行的時候佔用著幾百兆的記憶體,為什麼會這麼大呢?
通過 jstack 檢視執行緒的執行狀態發現很多執行緒都WAITING在列印日誌這裡了.
通過程式碼分析,我們的日誌列印的太多了,我們的日誌列印模式是ASYNC非同步的.
原來由於非同步列印日誌,列印的大物件就一直無法被回收掉,列印日誌又會寫盤,所以才會頻繁GC而且吞吐量極低
"http-nio-8000-exec-193" #2041 daemon prio=5 os_prio=0 tid=0x00007fe91c031000 nid=0x120f waiting on condition [0x00007fe9304cc000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000ab7334a8> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
at java.util.concurrent.locks.ReentrantLock$NonfairSync .lock(ReentrantLock.java:209)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:210)
at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:235)
at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:100)
at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84)
at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51)
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421)
at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383)
at ch.qos.logback.classic.Logger.debug(Logger.java:482)
複製程式碼
另外還發現程式碼中有一些重複的邏輯以及一些沒必要的大物件
所以要著手開始優化
優化
- 調整日誌級別
- 去掉沒必要的邏輯
- 優化沒必要的大物件
- 讀取redis時使用pipeline
執行緒數 | 平均耗時 | 總呼叫次數 | 異常次數 | 平均吞吐量 |
---|---|---|---|---|
300 | 688 | 109832 | 0 | 413.2/S |