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

  • 时间:
  • 浏览:1

就让发布过一篇博文 下单快发货慢:另另一个 JOIN SQL 引起 SqlClient 读取数据慢的奇特疑问报告 ,当时遇到的疑问报告 是从 SQL Server 508 R2 中查询获取 50 条记录竟然耗时 10 多秒,排查中发现疑问报告 与 SQL  查询中中有 INNER JOIN 有关,加进去 INNER JOIN 立马查询太快了 。当时天真地以为因为 是 JOIN 的那张表数据记录越多以及主表聚集索引不合理,于是采用将 INNER JOIN 每项拆分出来单独查询临时防止了疑问报告 。

这半个月让让人们 都又在另外另另一个 ASP.NET Core 2.2 项目中也遇到了查询 50 数据库记录数率慢(必须4~6秒)的疑问报告 ,就让所查询的数据库表数据量并详细都是很大。通过 EF Core 的 日志记录发现耗时处在在 Executed DbCommand 时,耗时处在点与就让的清况 不一样,就让是处在在 Executed DbCommand 就让 SqlDataReader 从数据库读取数据时。

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

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

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 的表数据量不大,详细不机会造成 50 多倍的性能之差。看来上次归罪于 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毫秒,相差50多倍!你造是 System.Data.SqlClient 的另另一个 大 bug ,另另一个 潜藏就让(大约从 .NET Core 2.1 到 3.0 Preview 4)的巨坑。

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

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