記阿里雲 RDS MySQL 的一個大坑

技術譯民發表於2020-12-08
阿里MySql

花了一個下午的時間，終於把一個阿里雲 RDS MySQL 的一個大坑填上了，解決方法令人匪夷所思！絕對會讓各位看官感到大吃一驚，阿里雲 RDS MySQL 居然有這樣 xx 的大坑！

問題

最近應業務的需求，加了一個定時統計的任務，其中的演算法很簡單，只是需要大量的 CRUD 操作。
由於業務簡單，且時效性要求不高，所以程式碼寫起來若行雲流水，一氣呵成，本地測試一遍通過。
沒料想，當部署到線上測試的時候，卻上演了現場翻車，真是讓人大跌眼鏡……

看了一下錯誤日誌，大致如下所示：

ERROR [DAL.EvaluateDetails:403] GetCount [(null)] - GetCount Error :Authentication to host 'rdsxxxxxxxxxxxxxxxxx.mysql.rds.aliyuncs.com' for user 'juxxxxxxxxxx' using method 'mysql_native_password' failed with message: User juxxxxxxxxxx already has more than 'max_user_connections' active connections
MySql.Data.MySqlClient.MySqlException (0x80004005): Authentication to host 'rdsxxxxxxxxxxxxxxxxx.mysql.rds.aliyuncs.com' for user 'juxxxxxxxxxx' using method 'mysql_native_password' failed with message: User juxxxxxxxxxx already has more than 'max_user_connections' active connections ---> MySql.Data.MySqlClient.MySqlException (0x80004005): User juxxxxxxxxxx already has more than 'max_user_connections' active connections
   在 MySql.Data.MySqlClient.MySqlStream.ReadPacket()
   在 MySql.Data.MySqlClient.Authentication.MySqlAuthenticationPlugin.ReadPacket()
   在 MySql.Data.MySqlClient.Authentication.MySqlAuthenticationPlugin.AuthenticationFailed(Exception ex)
   在 MySql.Data.MySqlClient.Authentication.MySqlAuthenticationPlugin.ReadPacket()
   在 MySql.Data.MySqlClient.Authentication.MySqlAuthenticationPlugin.Authenticate(Boolean reset)
   在 MySql.Data.MySqlClient.NativeDriver.Open()
   在 MySql.Data.MySqlClient.Driver.Open()
   在 MySql.Data.MySqlClient.Driver.Create(MySqlConnectionStringBuilder settings)
   在 MySql.Data.MySqlClient.MySqlPool.GetPooledConnection()
   在 MySql.Data.MySqlClient.MySqlPool.TryToGetDriver()
   在 MySql.Data.MySqlClient.MySqlPool.GetConnection()
   在 MySql.Data.MySqlClient.MySqlConnection.Open()
   在 Utility.MySqlDbHelper.PrepareCommand(MySqlCommand cmd, MySqlConnection conn, MySqlTransaction trans, CommandType cmdType, String cmdText, MySqlParameter[] cmdParms) 位置 D:\Work\git\Utility\MySqlDbHelper.cs:行號 322
   在 Utility.MySqlDbHelper.ExecuteReader(String connString, CommandType cmdType, String cmdText, MySqlParameter[] cmdParms) 位置 D:\Work\git\Utility\MySqlDbHelper.cs:行號 101
   在 DAL.EvaluateDetails.GetCount(String connStr, Nullable`1 startDate, Nullable`1 endDate, Nullable`1 marketingType) 位置 D:\Work\git\DAL\EvaluateDetails.cs:行號 403

User juxxxxxxxxxx already has more than 'max_user_connections' active connections……

What?!

問題分析

以前從來沒有遇到過 max_user_connections 這樣的錯誤，倒是遇到過幾次 max_connections，根據經驗，這種錯誤基本上都是使用連線後忘記關閉連線導致的。 是的，我一開始就是這麼想的，儘管作為多年耕耘於一線的資深程式設計老鳥，對於寫的程式碼滿懷信心，認為不可能犯這麼低階的錯誤，但暫時想不到別的問題。於是，開始圍繞這個思路展開復查和求證……

基本情況

先簡單介紹一下程式的情況：C# 開發，基於 .NET Framework 4.5.2（嗯~ o(￣▽￣)o，古老的執行框架，很多時候不得不這麼做，因為呼叫的類庫太多，且全基於這個框架，升級的成本太大）; 資料庫訪問呼叫的是 MySQL 官方提供的 MySql.Data（Version=6.9.7.0, Runtime: v4.0.30319）。

MySql.Data.dll Version

在阿里雲控制檯檢視一下這臺 MySQL Server 的配置情況：

RDS MySQL Configuration

資料庫中查詢一下連線數的配置情況：

SELECT @@max_user_connections, @@max_connections, @@wait_timeout, @@interactive_timeout;

查詢結果：

| max_user_connections | max_connections | wait_timeout | interactive_timeout |
| -------------------- | --------------- | ------------ | ------------------- |
| 600                  | 1112            | 7200         | 7200                |

max connections query

在控制檯檢視一下統計程式執行時的 IOPS 和 連線數：

IOPS and Connections 1

資料庫的配置是 max_user_connections = 600，程式執行時，總連線數確實超過了這項配置，報異常的原因就是這個，那麼是什麼引起的呢？

問題排查

1、檢查資料庫開啟後是否忘記關閉

程式實現的業務雖簡單，但資料庫的訪問和邏輯計算有太多了，大量的 CRUD 操作，使用到 MySqlCommand 的 ExecuteScalar 、ExecuteReader、ExecuteNonQuery 以及 MySqlDataAdapter 的 Fill 方法。一個一個看方法查下去，遺憾的是，發現所有的資料庫訪問之後都同步執行了 MySqlConnection 的 Close 方法。

雖然最先懷疑的就是這個原因，但事實證明並不是。除非 MySql.Data 內部在呼叫 Close 後實際上沒有立即 Close？ 用 ILSpy 檢視了原始碼，也沒有發現問題。

2、檢查程式中的併發邏輯

另一個可以想到的原因就是，併發 CRUD 太多？

上面我說過，因為這個程式的時效性要求不高，為避免給資料庫服務帶來壓力，根本沒有用到併發處理。

那到底是什麼原因引起的呢？

3、關於 max_user_connections 的思考

錯誤提示是 使用者 juxxxxxxxxxx 的活動連線數已超過 'max_user_connections'，注意這裡提示的是活動連線數。

到官網檢視一下配置項 max_user_connections [1] 和 max_connections [2] 的解釋：

max connections

max user connections

max_connections 是允許的最大併發客戶端連線數，max_user_connections 是給定使用者賬號允許的最大併發連線數。注意它們都是併發數。

報錯日誌中的 活動連線數 正好是對應 MySQL​ 官方說的 併發連線數 。

問題是，明明每次執行 CRUD 後都關閉了連線，而且程式是單執行緒執行的，為什麼活動連線數還是超出了 max_user_connections 的值 600 呢？

難道……

難道說……

難道說這裡的併發數指的每秒或者每分鐘的累計數？？？

不可能啊，

官方的文件中沒有提到 per second 或者 per minute 啊！

Google 了一下，也查到不到類似的說法啊！

那是不是阿里雲改了 MySQL 底層，做了 per second 或者 per minute 的限制呢？

想不出別的原因了，死馬當活馬醫，試一下吧！

問題解決

本來就是單執行緒執行的程式，為了降低 CRUD 操作的頻率，只好在迴圈執行的邏輯中每次迴圈後新增 Thread.Sleep 等待。
將程式碼改成大概如下的樣子：

// ...

for (DateTime dt = startDate; dt <= endDate; dt = dt.AddMonths(1))
{
    foreach (var shopInfo in list)
    {
        StatisticOneStore(shopInfo, dt);
        Thread.Sleep(1000); //第一處 Sleep
    }
}

// ...

private void StatisticOneStore(ShopInfo shopInfo, DateTime statisticDate)
{
    // 其他業務邏輯 ...

    foreach (var item in normalList)
    {
        SaveToDb(shopInfo, item, MarketingType.Normal, dbMonth);
        Thread.Sleep(50); //第二處 Sleep
    }

    // 其他業務邏輯 ...

    foreach (var item in eventList)
    {
        SaveToDb(shopInfo, item, MarketingType.Event, dbMonth);
        Thread.Sleep(50); //第三處 Sleep
    }

    //...
}

// ...

然後再重新發布到伺服器上進行測試，雖然執行的速度慢了一點兒，但執行完成後檢視執行日誌，驚喜的發現，沒有報錯了！

再在控制檯檢視一下程式執行時的 IOPS 和 連線數：

IOPS and Connections 2

連線數居然降至不到原來的一半了！！！

折騰了半天，最終居然只是加了個 Sleep 問題便解決了，實在是太出乎意料了！

大跌眼鏡，有沒有？！

好在程式沒有那麼高的時效性要求，不然只能升級 MySQL Server 的配置規格了。

總結

問題雖然是解決了，但是依然有個疑惑，MySQL 官方文件上明明說的是併發連線數限制，為什麼在阿里雲 RDS MySQL 中，卻感覺是限制了每個 MySQL 例項每秒或每分的累計連線數呢？

不知道有沒有別的朋友遇到過這樣的問題？

不管怎樣，問題解決了，聊以記之，以儆效尤。

  1. https://dev.mysql.com/doc/refman/8.0/en/server-system-variables.html#sysvar_max_user_connections max_user_connections ↩︎

  2. https://dev.mysql.com/doc/refman/8.0/en/server-system-variables.html#sysvar_max_connections max_connections ↩︎

相關文章