連接數從異常到 300 到 5(記 RDS MySQL 的一個大坑)


花了一個下午的時間,終於把一個 RDS MySQL 的一個大坑填上了,解決方法令人匪夷所思,絕對會讓各位看官感到大吃一驚!

問題

最近應業務的需求,加了一個定時統計的任務,其中的算法很簡單,只是需要大量的 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 實例每秒或每分的累計連接數呢?

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


(次日) 重要補充

錯怪了阿里雲 RDS😥😥😥,已找到真正原因和更優的解決方法,請看:連接數從異常到 300 到 5(RDS 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 ↩︎


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM