坑暗花明:又遇 .NET Core 中 System.Data.SqlClient 查詢緩慢的問題

以前發佈過一篇博文 下單快發貨慢:一個 JOIN SQL 引發 SqlClient 讀取數據慢的奇特問題,當時遇到的問題是從 SQL Server 2008 R2 中查詢獲取 100 條記錄居然耗時 10 多秒,排查中發現問題與 SQL  查詢中包含 INNER JOIN 有關,去掉 INNER JOIN 立馬查詢飛快。當時天真地覺得緣由是 JOIN 的那張表數據記錄太多以及主表彙集索引不合理,因而採用將 INNER JOIN 部分拆分出來單獨查詢臨時解決了問題。html

這兩天咱們又在另一個 ASP.NET Core 2.2 項目中也遇到了查詢 100 數據庫記錄速度慢(須要4~6秒)的問題,並且所查詢的數據庫表數據量並非很大。經過 EF Core 的 日誌記錄發現耗時發生在 Executed DbCommand 時,耗時發生點與以前的狀況不同,以前是發生在 Executed DbCommand 以後 SqlDataReader 從數據庫讀取數據時。git

2019-05-11T14:21:38.1015229+08:00 [INFORMATION] Executed DbCommand ("5,850"ms)

而經過 SQL Server Management Studio 執行一樣的 SQL 語句只須要 20 毫秒左右,相差200多倍。github

Executed DbCommand 日誌記錄的是 dbCommand.ExecuteReaderAsync 執行的時間(詳見 EF Core 的源碼數據庫

result = new RelationalDataReader(
    connection,
    dbCommand,
    await dbCommand.ExecuteReaderAsync(cancellationToken),
    commandId,
    Logger);

dbCommand.ExecuteReaderAsync 的實現代碼在 corefx 的 System.Data.SqlClient 中,若是是 .net core 的問題,那問題就出在 System.Data.SqlClient 。post

在上次排查 SqlDataReader 讀取數據速度慢問題,就曾懷疑 System.Data.SqlClient ,花了不少時間在 System.Data.SqlClient 的源碼中打點排查,最終沒有找到線索,此次不敢輕易懷疑它。性能

雖然此次的耗時發生點與上次不同,但此次的 SQL 查詢語句中有個地方和上次是同樣的,也包含 INNER JOIN 查詢,因而試着去掉 INNER JOIN ,Executed DbCommand 只需2毫秒。測試

[INFORMATION] Executed DbCommand ("2"ms)

啊,怎麼也與 INNER JOIN 有關,沒道理啊,此次 JOIN 的表數據量不大,徹底不可能形成 200 多倍的性能之差。看來上次歸罪於 INNER JOIN ,多是冤枉它了,得從新思考與排查這個問題。url

因爲問題是在某個時間點以後出現,因而採起笨方法,回退 git 提交歷史直至問題消失。。。spa

最終發現,居然是在一次 git commit 中給這個查詢在 SELECT 時增長了1個字段引發的, 去掉這個字段,問題立馬消失。進一步測試發現,只要任意去掉 SELECT 中的1個字段,就不會出現問題,太奇怪了。數了數 SELECT 中有20個字段,難道與 SELECT 字段的數量有關?以前的項目會不會也與 SELECT 字段的數量有關?.net

因而回到以前的項目,恢復 INNER JOIN 查詢,這時驚訝地發現 SqlDataReader 讀取數據速度慢的問題居然消失了。回想當時處理問題後到如今所作的變動,惟一的變動就是從 .NET Core 3.0 Preivew 4 升級到 .NET Core 3.0 Preivew 5 ,難道 3.0 Preivew 5 把這個問題給修復了?難道真的是 System.Data.SqlClient 的 bug ?

答案很容易驗證,將當前遇到 Executed DbCommand 執行慢的項目升級到 .NET Core 3.0 Preivew 5 ,昨天晚上完成升級後

Executed DbCommand ("3"ms)

飛流直下三千尺,從4秒驟降到3毫秒,相差1000多倍!果真是 System.Data.SqlClient 的一個大 bug ,一個潛藏好久(至少從 .NET Core 2.1 到 3.0 Preview 4)的巨坑。

這個詭異問題的謎底在偶然間終於被解開了,這時又產生了新的疑問 —— corefx 中是如何修復這個巨坑 bug 的?

查看 corefx 中與 System.Data.SqlClient 相關的 git commits ,目測發現下面的 commit (對應的 PR ),也許是這個 commit 修復的,接下來找時間驗證一下。

相關文章
相關標籤/搜索