服務端性能優化：Troubleshooting 兩則

這篇文章的內容是兩年前的兩個多IDC高延遲的Troubleshooting，經過仔細的分析和定位，最終解決，并對線上業務起到了很好的優化效果。分享給大家，共同交流學習。

最近在梳理某項目上各服務接口的性能情況，遇到兩個問題。以下是定位和解決問題的一個思路，分享給大家。

業務之前并沒有詳細的性能日志記錄，僅在電信機房(T機房)進行了性能測試，結果是各接口滿足預期，服務上線。

在進一步對接口進行性能分析時，對各業務接口的關鍵路徑添加了日志統計，通過日志進行分析，將接口的延遲進行統計，接入Grafana，觀察數據后，發現兩類問題。

1. 連接MongoDB的服務，網通機房(C機房)延遲比電信機房(T機房)要高。

2. 連接Mysql的服務，網通機房(C機房)延遲比電信機房(T機房)高。

   NOTE: 這些服務接口，都是只讀，沒有寫操作。

   對兩類問題分別進行排查:

MongoDB

簡單的排查后發現，MongoDB實例有過一次遷移，并且遷移后只保留了電信機房(T機房)的實例，網通機房(C機房)沒有從庫，所以網通機房(C機房)延遲比電信機房(T機房)高。對網通機房(C機房)部署了從庫實例后，卻意外發現電信機房(T機房)的延遲比網通機房(C機房)高了。再次排查后發現，代碼中配置的MongoDB的讀策略是secondary（從庫優先），所以網通機房(C機房)有從庫后，電信機房(T機房)也去網通機房(C機房)讀取，導致了電信機房(T機房)的延遲變高。更改讀策略為nearest（就近優先），有所好轉，但并沒有預想的效果那么好。仔細看下官方文檔

The driver reads from a random member of the set that has a ping time that is less than 15ms slower than the member with the lowest ping time. Reads in the MongoClient::RP_NEAREST mode do not consider the member’s type and may read from both primaries and secondaries.

就會發現， nearest是在客戶端維護一個到各個實例延遲小于15ms的集合 ，而我們電信機房(T機房)到網通機房(C機房)是光纖直連，延遲在12ms左右，所以，每次客戶端可能會連接到電信機房(T機房)，也可能到網通機房(C機房)。

這點在以后的應用中，大家可以注意下。

Mysql

在所有的服務中，只有一個服務接口是讀mysql實現的，而這個接口的表現更是奇怪，網通機房(C機房)的延遲比電信機房(T機房)多100 ms+。

開始時猜測有可能業務內做了某些寫主庫的操作，比如寫mysql，或寫redis之類的，跨機房寫導致的延遲高。

實際分析后發現，業務內并沒有寫操作，多出的時間就是讀mysql的時間。

mysql是有網通機房(C機房)的從庫的，為什么讀取從庫的數據，延遲還會這么高呢。在我們服務端ping 網通機房(C機房)的mysql ip，發現延遲正常，只有零點幾毫秒，不存在網絡問題。

下一步就是通過抓包，分析下我們服務端跟mysql間到底有哪些交互，到底是哪個環節慢了。

根據抓包結果發現，正常的select查表請求很快能得到響應，但當從我們服務端發送一個 “Describe tableName”的請求到mysql 服務端時，服務端等待了較長時間(30ms+)才返回結果，而且一次接口服務請求中，有多次Describe的請求，這樣，導致網通機房(C機房)最終延遲很高。

問題定位后，開始嘗試解決。

解決問題前需要先理清思路：

1. DescribeTableName 這個命令是干什么用的，業務里并沒有顯式調用。這個請求能不能去掉。

2. 如果不能去掉，那它的延遲為什么這么高，能不能優化？

第一個問題比較簡單，Describe 命令是現在ORM中比較通用的做法，通過獲取數據庫的表結構，來動態的創建Model。如果不調用Describe命令，當然也可以做到，那樣就需要自己業務端對每個model進行聲明，這樣開發成本會大大增加，這個方式不可取。所以需要保留Describe命令。

第二個問題，延遲為什么高，這個命令是很簡單的一個命令，沒有任何復雜的操作，而且主庫上都沒有這個問題。結合DBA同學在Mysql上使用了Atlas中間件，可以大膽猜想下，應該是這個中間件搞的鬼，把select請求分配到從庫執行，但是把Describe分配到了主庫執行，有可能是因為Atlas中間件只考慮了一些讀的SQL，把這類請求分配到從庫，而其它各種請求，可能由于過于復雜，就默認分配到主庫去執行。當然這只是猜測，沒有查看過Atlas的源碼，所以不能妄下結論。結合已經整理到的線索，跟DBA同學進行了確認，確定 Describe命令確實被Atlas中間件發送到主庫去執行了，至于這么做的原因， 是為了避免主從結構不一致時，從庫拿到的表結構錯誤 。這種情況下，我們也不能評價說中間件做的到底合理不合理，所以我們需要從自己的角度再思考下能不能優化。如果說希望避免每次請求都執行Describe命令，除了說剛才提到的自己聲明，另外一個方式就是cache了，因為表結構變化的頻次太低了，我們完全可以設置一個較長時間的cache，來避免頻繁的這種請求。業務使用的是  Phalcon 框架，這個框架中已經提供了這種meta-Data cache的方案,Yii中也有類似的實現: schemaCaching。

當啟用這種cache后，效果就很明顯，可以看到：

網通機房(C機房)延遲從原來的120ms降到7ms, 電信機房(T機房)延遲從原來的10ms降低到5ms.

后續需要考慮的就是，如果表結構發生變化，如何在不影響業務的情況下進行更新。這個也可以有多種實現的方案，大家可以自己想下。

總結

解決問題的思路就在于，遵循最小化原則，先對可能產生這種問題原因進行大膽猜測，然后快速驗證，逐步縮小范圍，將問題定位到一個最小可復現的范圍內，再深入分析具體原因。當然這一切都要有數據說話，如果平時開發中，能提供足夠豐富的日志數據，就可以很快的定位問題，甚至提前發現問題。

最后插個廣告，猜猜我畫的是啥？

 

來自：https://mp.weixin.qq.com/s/4Fq7gLoV1my7UT-h9VI0ig