1. 程式人生 > >【故障公告】SQL語句執行超時引發網站首頁訪問故障

【故障公告】SQL語句執行超時引發網站首頁訪問故障

非常抱歉,今天早上 6:37~8:15 期間,由於獲取網站首頁博文列表的 SQL 語句出現突發的查詢超時問題,造成訪問網站首頁時出現 500 錯誤,由此給您帶來麻煩,請您諒解。

故障的情況是這樣的。

故障期間日誌中記錄了大量下面的錯誤。

2020-02-03 06:37:24.635 [Error] An unhandled exception has occurred while executing the request.
/
Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware
System.Data.SqlClient.SqlException (0x80131904): Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
 ---> System.ComponentModel.Win32Exception (258): Unknown error 258
   at System.Data.SqlClient.SqlCommand.<>c.<ExecuteDbDataReaderAsync>b__126_0(Task`1 result)

資料庫伺服器(阿里雲 RDS SQL Server 2016 例項)的 CPU 消耗突增。

資料庫伺服器的 IOPS 暴增。

通過阿里雲 RDS 控制檯的 CloudDBA 可以檢視到故障期間獲取首頁博文的 SQL 語句被執行了3萬多次,執行這麼多次是由於查詢超時,無法建立快取,每次請求都要訪問資料庫。

發現故障後,我們通過阿里雲 RDS 的主備切換恢復了正常。

經過對故障的排查分析,鎖定的最大嫌疑物件是 SQL Server 引數嗅探(詳見園子裡的博文 什麼是 SQL Server 引數嗅探)。

對於這種因為重用他人生成的執行計劃而導致的水土不服現象,SQL Server 有一個專有名詞,叫“引數嗅探 parameter sniffing”。

而且我們找到了引發 SQL Server 引數嗅探問題的條件。

在我們的 open api 中提供了獲取首頁博文列表的 web api ,但沒有限制可以獲取的最大博文數,也就是下面的 ItemCount 引數(除了 open api ,其他地方呼叫時 ItemCount 值都是 20 )。

SELECT TOP (@ItemCount)

假如有人呼叫 open api 時給 ItemCount 傳了一個很大的值,比如 20000 ,雖然呼叫的是同樣的 SQL 語句,但由於 ItemCount 的值不同, SQL Server 可能會生成相差很大的執行計劃,對於 ItemCount 20000 效能比較好的執行計劃,對於 ItemCount 20 可能效能極差。如果查詢 ItemCount 20000 時生成的執行計劃被快取下來,查詢 ItemCount 20 時繼續使用這個執行計劃,就會出現本來好好的 SQL 查詢突然變得效能極差。我們今天遇到的故障很可能就是這個原因,而且故障時就一個 SQL 語句出現問題(正好就這個 SQL 查詢快取了水土不服的執行計劃),其他都正常,也驗證了這個猜測。

通過這次故障,我們吸取的教訓是一定要在程式碼中對 ItemCount 與 PageSize 的最大值進行限制,它不僅僅是帶來不必要的低效能查詢,而且可能會因為 SQL Server 引數嗅探問題拖垮整個資料庫。