起源
最近一直在跟大佬們做公司專案的效能最佳化,我這種小卡樂咪基本上負責的就是慢介面最佳化,但實際上只有以下幾種情況需要進行介面程式碼級別的改造:
- 迴圈查庫、RPC
- 資料庫設計不合理
- 業務流程太長,程式碼耦合性太高等
隨著對介面分析的深入,我們越來越發現系統中有很多拖後腿的問題是與業務程式碼無關的,今天要分享的這個是關於MyBatis大名鼎鼎的第三方分頁外掛PageHelper
在生成count
語句時,若語句引數數量過大導致的效能問題。
初步發現問題
在對慢介面進行日誌分析的時候,我們發現一些count
語句日誌的列印較上一行隔了很久,而從程式碼上來看,到上一行日誌列印後,這中間沒有做什麼耗時操作。
一番排查後,我們發現這種慢的語句具有如下特性:
- 都是來自於分頁查詢中自動生成的
count
- 都具有大量的引數(示例中是7000+個)
簡單排查
雖然我們很懷疑這7000多個引數,這2000ms會不會花在網路IO或資料庫查詢上了,畢竟這種大量in
的幾乎都是全表查詢,但冷靜下來想一想,根據MyBatis列印SQL的一貫套路,可以推斷出這個耗時肯定不是count
語句實際執行產生的IO耗時或網路等待,因為在列印這行語句時SQL應該還沒有執行。
插一嘴:由於我們表的資料量並不大,幾十萬級別,並且有覆蓋in查詢條件的索引可以利用,這大大減少了要掃描的頁面數量,實際
count
語句執行只需要幾十ms
在執行到該位置時觀察CPU,當時幾乎是單核心跑滿的,所以當時一定在做一些CPU操作。
至此,已經開始懷疑是語句引數數量過大導致的SQL編譯大量耗費CPU,但又考慮到一個現代的CPU不可能被這種簡單的任務難住,於是決定jstack抓一下當時CPU究竟在幹什麼:
從堆疊上看,CPU當時肯定是在編譯SQL沒跑了,本地執行程式碼Debug到PageHelper中,也發現最終在getSmartCountSql
中呼叫jSqlParser.parse
來生成分頁SQL時耗費了1到2s:
在count
之後,Mybatis自己也要編譯這個具有大量in
引數的SQL,而它只花了6ms,至此已經可以完全斷定是PageHelper的效能問題了。
這種純CPU的效能問題是不可擴充套件的,若你有一個四核心的CPU,CPU處理的總能力肯定只能在2s鍾內執行完4個編譯任務,假設有80個併發,這個編譯時間只會越來越長。
官方issue中有兩個人反饋了這個問題,但官方貌似持擺爛態度2
替換策略
聯絡大佬移除底層腳手架中的PageHelper,使用MyBatis內部的分頁外掛,效能回歸正常
猜想
由於PageHelper內部使用的JSqlParser
實現是CCJSqlParser
,其是C語言實現的,懷疑是不是在引數量大時需要在native堆疊和JVM堆疊中大量傳遞資料導致的呢?目前不瞭解JNI,這個不敢妄下結論了。