坑暗花明:又遇 .NET Core 中 System.Data.SqlClient 查询缓慢的问题

  • 时间:
  • 浏览:0

日后发布过一篇博文 下单快发货慢:另一个多 JOIN SQL 引起 SqlClient 读取数据慢的奇特疑问,当时遇到的疑问是从 SQL Server 1508 R2 中查询获取 1150 条记录竟然耗时 10 多秒,排查中发现疑问与 SQL  查询中包含 INNER JOIN 有关,加在 INNER JOIN 立马查询比较慢。当时天真地以为原因分析是 JOIN 的那张表数据记录过多以及主表聚集索引不合理,于是采用将 INNER JOIN 每段拆分出来单独查询临时外理了疑问。

这3天你们又在另外另一个多 ASP.NET Core 2.2 项目中也遇到了查询 1150 数据库记录时延慢(都要4~6秒)的疑问,日后所查询的数据库表数据量并也有很大。通过 EF Core 的 日志记录发现耗时处在在 Executed DbCommand 时,耗时处在点与日后的请况不一样,日后是处在在 Executed DbCommand 日后 SqlDataReader 从数据库读取数据时。

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

而通过 SQL Server Management Studio 执行同样的 SQL 的话只都要 20 毫秒左右,相差150多倍。

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 。

在上次排查 SqlDataReader 读取数据时延慢疑问,就曾怀疑 System.Data.SqlClient ,花了一点时间在 System.Data.SqlClient 的源码中打点排查,最终都如此找到线索,这次不敢轻易怀疑它。

其实这次的耗时处在点与上次不一样,但这次的 SQL 查询的话包含个地方和上次是一样的,也包含 INNER JOIN 查询,于是试着加在 INNER JOIN ,Executed DbCommand 只需2毫秒。

[INFORMATION] Executed DbCommand ("2"ms)

啊,为什么在也与 INNER JOIN 有关,没道理啊,这次 JOIN 的表数据量不大,完整篇 不肯能造成 150 多倍的性能之差。看来上次归罪于 INNER JOIN ,肯能是冤枉它了,得重新思考与排查这些 疑问。

肯能疑问是在某个时间点日后再次再次出现,于是采取笨最好的办法,回退 git 提交历史直至疑问消失。。。

最终发现,竟然是在一次 git commit 中给这些 查询在 SELECT 时增加了另一个多字段引起的, 加在这些 字段,疑问立马消失。进一步测试发现,日后我任意加在 SELECT 中的另一个多字段,就后会再次再次出现疑问,太奇怪了。数了数 SELECT 包含20个字段,难道与 SELECT 字段的数量有关?日后的项目会后会也与 SELECT 字段的数量有关?

于是回到日后的项目,恢复 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毫秒,相差11150多倍!果果真 System.Data.SqlClient 的另一个多大 bug ,另一个多潜藏日后(共要从 .NET Core 2.1 到 3.0 Preview 4)的巨坑。

这些 诡异疑问的谜底在偶然间终于被解开了,这时又产生了新的疑问 —— corefx 中是如可修复这些 巨坑 bug 的?

查看 corefx 中与 System.Data.SqlClient 相关的 git commits ,目测发现下面的 commit (对应的 PR ),跟我说是这些 commit 修复的,接下来找时间验证一下。