首页 > 解决方案 > EF Core:简单查询 - 为什么这么慢?

问题描述

EF 核心版本:3.1。

这是我的方法:

public static ILookup<string, int> GetClientCountLookup(DepotContext context, DateRange dateRange)
            => context
                .Flows
                .Where(e => e.TimeCreated >= dateRange.Start.Date && e.TimeCreated <= dateRange.End.Date)
                .GroupBy(e => e.Customer)
                .Select(g => new { g.Key, Count = g.Count() })
                .ToLookup(k => k.Key, e => e.Count);

使用的所有字段均已编入索引。

这是生成的查询:

SELECT [f].[Customer] AS [Key], COUNT(*) AS [Count]
FROM [Flows] AS [f]
WHERE ([f].[TimeCreated] >= @__dateRange_Start_Date_0) AND ([f].[TimeCreated] <= @__dateRange_End_Date_1)
GROUP BY [f].[Customer]

当该查询作为 SQL 执行时,执行时间为 100 毫秒。在带有方法的代码中使用该查询时ToLookup- 执行时间为 3200 毫秒。

更奇怪的是 - EF Core 中的执行时间似乎完全独立于数据样本大小(比方说,根据日期范围,我们可以计算数百或数十万条记录)。

这里到底发生了什么?

我粘贴的查询是 EF Core 发送的真实查询。我首先粘贴的代码片段在 3200ms 内执行。然后我使用了精确生成的 SQL 并在 Visual Studio 中作为 SQL 查询执行——花了 100 毫秒。

这对我来说没有任何意义。我使用 EF Core 很长一段时间,它似乎表现合理。大多数查询(简单、简单、没有日期范围)很快,可以立即获取结果(不到 200 毫秒)。

在我的应用程序中,我构建了一个非常庞大的查询,其中包含 4 个多列连接和子查询……猜猜看 - 它在 3200 毫秒内获取 400 行。它还在 3200 毫秒内获取 4000 行。而且当我删除大部分连接时,包括,甚至删除子查询 - 3200ms。或 4000,取决于我的 Internet 或服务器的瞬时状态和负载。

这就像不断滞后,我将其精确定位到我粘贴的第一个查询。

我知道ToLookup方法导致最终获取所有输入表达式结果,但在我的情况下(真实世界数据) - 正好有 5 行。

结果如下所示:

|------------|-------|
| Key        | Count |
|------------|-------|
| Customer 1 | 500   |
| Customer 2 | 50    |
| Customer 3 | 10    |
| Customer 4 | 5     |
| Customer 5 | 1     |

从数据库中获取 5 行需要 4 秒?!这太荒谬了。如果获取了整个表,则对行进行分组和计数——这将加起来。但是生成的查询实际上返回 5 行。

这里发生了什么,我错过了什么?

请不要要求我提供完整的代码。它是机密的,是我客户项目的一部分,我不允许泄露我客户的商业机密。不是这里,也不是任何其他问题。我知道当你没有我的数据库和整个应用程序时很难理解会发生什么,但这里的问题是纯理论的。要么你知道发生了什么,要么你不知道。就如此容易。这个问题虽然非常难。

我只能说使用的 RDBMS 是远程运行在 Ubuntu 服务器上的 MS SQL Express。测量的时间是对远程数据库执行代码测试 (NUnit) 或查询的时间,所有这些都是在我的 AMD Ryzen 7 8 核 3.40GHz 处理器上执行的。服务器位于 Azure 上,例如 I5 2.4GHz 的 2 核或类似的东西。

标签: sql-serverentity-framework-core

解决方案


这是测试:

[Test]
public void Clients() {
    var dateRange = new DateRange {
        Start = new DateTime(2020, 04, 06),
        End = new DateTime(2020, 04, 11)
    };
    var q1 = DataContext.Flows;
    var q2 = DataContext.Flows
        .Where(e => e.TimeCreated >= dateRange.Start.Date && e.TimeCreated <= dateRange.End.Date)
        .GroupBy(e => e.Customer)
        .Select(g => new { g.Key, Count = g.Count() });
    var q3 = DataContext.Flows;
    var t0 = DateTime.Now;
    var x = q1.Any();
    var t1 = DateTime.Now - t0;
    t0 = DateTime.Now;
    var l = q2.ToLookup(g => g.Key, g => g.Count);
    var t2 = DateTime.Now - t0;
    t0 = DateTime.Now;
    var y = q3.Any();
    var t3 = DateTime.Now - t0;
    TestContext.Out.WriteLine($"t1 = {t1}");
    TestContext.Out.WriteLine($"t2 = {t2}");
    TestContext.Out.WriteLine($"t3 = {t3}");
}

这是测试结果:

t1 = 00:00:00.6217045 // the time of dummy query
t2 = 00:00:00.1471722 // the time of grouping query
t3 = 00:00:00.0382940 // the time of another dummy query

是的:147 毫秒是我之前花费 3200 毫秒的分组。发生了什么?之前执行了一个虚拟查询。

这就解释了为什么结果几乎不依赖于数据样本大小!

巨大的无法解释的时间是初始化,而不是实际的查询时间。我的意思是,如果不是之前的虚拟查询,那么整个时间都会在ToLookup代码行上流逝!该行将初始化 DbContext,创建与数据库的连接,然后执行实际查询并获取数据。

因此,作为最终答案,我可以说我的测试方法是错误的。我测量了第一次查询到我的DbContext. 这是错误的,应该在测量时间之前初始化数据库。我可以通过在测量查询之前执行任何查询来做到这一点。

好吧,出现了另一个问题——为什么第一个查询这么慢,为什么初始化这么慢。如果我的 Blazor 应用程序将使用DbContextas Transient(每次注入时实例化) - 每次会花费这么多时间吗?我不这么认为,因为这是我的应用程序在重大重新设计之前的工作方式。它没有明显的延迟(在页面之间切换时我会注意到 3 秒的延迟)。但我不确定。现在我的应用程序使用了 scoped DbContext,所以它是用于用户会话的。所以我根本看不到初始化开销,所以 - 在虚拟查询之后测量时间的方法似乎是准确的。


推荐阅读