下单快发货慢：一个 JOIN SQL 引起 SqlClient 读取数据慢的奇特问题 - 好文

更新：这个问题是 System.Data.SqlClient 的一个 bug 引起的，详见坑暗花明：又遇 .NET Core 中
System.Data.SqlClient 查询缓慢的问题 <https://www.cnblogs.com/dudu/p/10848435.html>

最近遇到一个非常奇特的问题，在一个 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 字段上有关，但目前没法修改聚集索引进行验证，以后再找机会验证。

热门工具换一换