下單快發貨慢：一個 JOIN SQL 引起 SqlClient 讀取數據慢的奇特問題

更新：這個問題是 System.Data.SqlClient 的一個 bug 引起的，詳見 坑暗花明：又遇 .NET Core 中 System.Data.SqlClient 查詢緩慢的問題

最近遇到一個非常奇特的問題，在一個 ASP.NET Core 項目中從 SQL Server 2008 R2 中查詢獲取 100 條記錄竟然耗時 10 多秒，如果是查詢本身慢，那到不是什么奇特的問題。

說它非常奇特是因為耗時主要發生在 SqlDataReader 讀取數據時

2019-04-04 21:31:58.546 [Information] Executed DbCommand ("2,656"ms)
...
2019-04-04 21:32:10.690 [Debug] A data reader was disposed.

進一步測試發現

查詢獲取 1 條數據庫記錄，耗時在 230ms 左右  
查詢獲取 10 條數據庫記錄，耗時在 1.6s-2s 之間
查詢獲取 100 條數據庫記錄，耗時在 12s-22s 之間

開始懷疑是 EF Core 的問題，通過在 EF Core 源碼中打點，定位到耗時發生在 _dataReader.ReadAsync 處

while (await _dataReader.ReadAsync(cancellationToken))
{
    _buffer.Enqueue(_valueBufferFactory.Create(_dbDataReader));
}

_dataReader.ReadAsync 實際調用的是 System.Data.SqlClient 中的 SqlDataReader.ReadAsync 方法。

一次 ReadAsync 讀取一行記錄，通過在 SqlClient 的源代碼中打點記錄時間戳發現，在 100 次一行一行讀取中，其中有幾次讀取會出現延遲，比如某一次 13 秒延遲，100 次讀取中出現了 5 次讀取延遲 —— 2s + 3s + 3s + 2s + 3s = 13s 。

經過在 System.Data.SqlClient 源代碼中無數次打點記錄時間戳最終定位到延遲發生在  SNIPacket.ReadFromStreamAsync()  方法中  stream.ReadAsync()  時

Console.WriteLine($"Entering stream.ReadAsync() at {DateTime.Now}");
stream.ReadAsync(_data, 0, _capacity, CancellationToken.None).ContinueWith(t =>
{
    Console.WriteLine($"stream.ReadAsync().ContinueWith at {DateTime.Now}");
    //...
}

stream 對應的是 NetworkStream ，延遲發生在網絡傳輸過程中，與 SqlClient 沒關系。

TCP 抓包發現 SQL Server 服務器發送的數據到達就延遲了。

於是只能將懷疑對象鎖定在 SQL Server 數據庫層面。

對應的 SQL 查詢語句涉及 4 張表，FROM 一張表（表A）， JOIN 三張表（LEFT JOIN 表B，LEFT JOIN 表C ，INNER JOIN 表D），表A有1000多萬條記錄，表C有1000多萬條記錄，查詢時按表A的主鍵排序，表A的聚集索引建在時間字段上，沒有建在主鍵上。

SELECT ...
FROM TableA
LEFT JOIN TableB ON [TableA].[Id] = [TableB].[EntryID]
LEFT JOIN TableC ON [TableA].[Id] = [TableC].[EntryID]
INNER JOIN TableD  ON [TableA].[BlogID] = [TableD].[BlogID]
WHERE ([TableA].[Id] >= @__startId_0)

並不是所有查詢都出現這個問題，當 @__startId_0 小於一定值時會出現。

后來嘗試將  LEFT JOIN TableC 改為 INNER JOIN TableC ，問題竟然消失了，但進一步測試發現當  @__startId_0  再小到一定值問題又會出現。

既然問題與 JOIN TableC 有關，那干脆不進行 JOIN ，單獨查詢 TableC ，然后將在 C# 代碼中將查詢的結果合並進行，這樣改進了，查詢獲取 100 條記錄只需 200 多毫秒。

這個奇特的問題就這樣用一個簡單粗暴有效的方法臨時解決了。

對於這個問題的根本原因，懷疑與 TableA 沒有把聚集索引建在 Id 字段上有關，但目前沒法修改聚集索引進行驗證，以后再找機會驗證。