实体框架异步操作需要十倍的时间才能完成

Dyl*_*rry 135 c# asynchronous entity-framework async-await

我有一个使用Entity Framework 6处理数据库的MVC站点,我一直在尝试更改它,以便所有内容都作为异步控制器运行,并且对数据库的调用作为异步对应项运行(例如ToListAsync())而不是ToList())

我遇到的问题是,简单地将我的查询更改为异步会导致它们非常慢.

以下代码从我的数据上下文中获取"Album"对象的集合,并转换为相当简单的数据库连接:

// Get the albums
var albums = await this.context.Albums
    .Where(x => x.Artist.ID == artist.ID)
    .ToListAsync();
Run Code Online (Sandbox Code Playgroud)

这是创建的SQL:

exec sp_executesql N'SELECT 
[Extent1].[ID] AS [ID], 
[Extent1].[URL] AS [URL], 
[Extent1].[ASIN] AS [ASIN], 
[Extent1].[Title] AS [Title], 
[Extent1].[ReleaseDate] AS [ReleaseDate], 
[Extent1].[AccurateDay] AS [AccurateDay], 
[Extent1].[AccurateMonth] AS [AccurateMonth], 
[Extent1].[Type] AS [Type], 
[Extent1].[Tracks] AS [Tracks], 
[Extent1].[MainCredits] AS [MainCredits], 
[Extent1].[SupportingCredits] AS [SupportingCredits], 
[Extent1].[Description] AS [Description], 
[Extent1].[Image] AS [Image], 
[Extent1].[HasImage] AS [HasImage], 
[Extent1].[Created] AS [Created], 
[Extent1].[Artist_ID] AS [Artist_ID]
FROM [dbo].[Albums] AS [Extent1]
WHERE [Extent1].[Artist_ID] = @p__linq__0',N'@p__linq__0 int',@p__linq__0=134
Run Code Online (Sandbox Code Playgroud)

事实上,它不是一个大规模复杂的查询,但SQL服务器运行它需要将近6秒.SQL Server Profiler报告它需要5742毫秒才能完成.

如果我将我的代码更改为:

// Get the albums
var albums = this.context.Albums
    .Where(x => x.Artist.ID == artist.ID)
    .ToList();
Run Code Online (Sandbox Code Playgroud)

然后生成完全相同的SQL,但根据SQL Server Profiler,它只运行474ms.

该数据库在"Albums"表中有大约3500行,实际上并不是很多,并且在"Artist_ID"列上有一个索引,所以它应该非常快.

我知道async有开销,但让事情慢了十倍对我来说似乎有点陡峭!我在哪里错了?

rdu*_*com 275

我发现这个问题非常有趣,特别是因为我async随处可见Ado.Net和EF 6.我希望有人对这个问题给出解释,但事实并非如此.所以我试图在我身边重现这个问题.我希望你们中的一些人会觉得这很有意思.

第一个好消息:我复制了它:)差别很大.因子8 ...

第一个结果

首先我怀疑有什么事情要处理CommandBehavior,因为我读了一篇关于asyncAdo 的有趣文章,说:

"由于非顺序访问模式必须存储整行的数据,因此如果从服务器读取大列(例如varbinary(MAX),varchar(MAX),nvarchar(MAX)或XML),则会导致问题. )".

我怀疑ToList()CommandBehavior.SequentialAccessCommandBehavior.Default非同步的呼叫(非顺序,这可能会导致问题).所以我下载了EF6的源代码,并在任何地方放置了断点(CommandBehavior当然在哪里使用).

结果:没有.所有的调用都是用CommandBehavior.Default....所以我试着进入EF代码来理解发生了什么......并且...... ooouch ...我从来没有看到这样的委托代码,一切似乎都是懒惰的......

所以我试着做一些分析来了解发生了什么......

而且我想我有一些东西......

这是创建我基准测试的表的模型,其中有3500行,每行有256 Kb随机数据varbinary(MAX).(EF 6.1 - CodeFirst - CodePlex):

public class TestContext : DbContext
{
    public TestContext()
        : base(@"Server=(localdb)\\v11.0;Integrated Security=true;Initial Catalog=BENCH") // Local instance
    {
    }
    public DbSet<TestItem> Items { get; set; }
}

public class TestItem
{
    public int ID { get; set; }
    public string Name { get; set; }
    public byte[] BinaryData { get; set; }
}
Run Code Online (Sandbox Code Playgroud)

这是我用来创建测试数据和基准EF的代码.

using (TestContext db = new TestContext())
{
    if (!db.Items.Any())
    {
        foreach (int i in Enumerable.Range(0, 3500)) // Fill 3500 lines
        {
            byte[] dummyData = new byte[1 << 18];  // with 256 Kbyte
            new Random().NextBytes(dummyData);
            db.Items.Add(new TestItem() { Name = i.ToString(), BinaryData = dummyData });
        }
        await db.SaveChangesAsync();
    }
}

using (TestContext db = new TestContext())  // EF Warm Up
{
    var warmItUp = db.Items.FirstOrDefault();
    warmItUp = await db.Items.FirstOrDefaultAsync();
}

Stopwatch watch = new Stopwatch();
using (TestContext db = new TestContext())
{
    watch.Start();
    var testRegular = db.Items.ToList();
    watch.Stop();
    Console.WriteLine("non async : " + watch.ElapsedMilliseconds);
}

using (TestContext db = new TestContext())
{
    watch.Restart();
    var testAsync = await db.Items.ToListAsync();
    watch.Stop();
    Console.WriteLine("async : " + watch.ElapsedMilliseconds);
}

using (var connection = new SqlConnection(CS))
{
    await connection.OpenAsync();
    using (var cmd = new SqlCommand("SELECT ID, Name, BinaryData FROM dbo.TestItems", connection))
    {
        watch.Restart();
        List<TestItem> itemsWithAdo = new List<TestItem>();
        var reader = await cmd.ExecuteReaderAsync(CommandBehavior.SequentialAccess);
        while (await reader.ReadAsync())
        {
            var item = new TestItem();
            item.ID = (int)reader[0];
            item.Name = (String)reader[1];
            item.BinaryData = (byte[])reader[2];
            itemsWithAdo.Add(item);
        }
        watch.Stop();
        Console.WriteLine("ExecuteReaderAsync SequentialAccess : " + watch.ElapsedMilliseconds);
    }
}

using (var connection = new SqlConnection(CS))
{
    await connection.OpenAsync();
    using (var cmd = new SqlCommand("SELECT ID, Name, BinaryData FROM dbo.TestItems", connection))
    {
        watch.Restart();
        List<TestItem> itemsWithAdo = new List<TestItem>();
        var reader = await cmd.ExecuteReaderAsync(CommandBehavior.Default);
        while (await reader.ReadAsync())
        {
            var item = new TestItem();
            item.ID = (int)reader[0];
            item.Name = (String)reader[1];
            item.BinaryData = (byte[])reader[2];
            itemsWithAdo.Add(item);
        }
        watch.Stop();
        Console.WriteLine("ExecuteReaderAsync Default : " + watch.ElapsedMilliseconds);
    }
}

using (var connection = new SqlConnection(CS))
{
    await connection.OpenAsync();
    using (var cmd = new SqlCommand("SELECT ID, Name, BinaryData FROM dbo.TestItems", connection))
    {
        watch.Restart();
        List<TestItem> itemsWithAdo = new List<TestItem>();
        var reader = cmd.ExecuteReader(CommandBehavior.SequentialAccess);
        while (reader.Read())
        {
            var item = new TestItem();
            item.ID = (int)reader[0];
            item.Name = (String)reader[1];
            item.BinaryData = (byte[])reader[2];
            itemsWithAdo.Add(item);
        }
        watch.Stop();
        Console.WriteLine("ExecuteReader SequentialAccess : " + watch.ElapsedMilliseconds);
    }
}

using (var connection = new SqlConnection(CS))
{
    await connection.OpenAsync();
    using (var cmd = new SqlCommand("SELECT ID, Name, BinaryData FROM dbo.TestItems", connection))
    {
        watch.Restart();
        List<TestItem> itemsWithAdo = new List<TestItem>();
        var reader = cmd.ExecuteReader(CommandBehavior.Default);
        while (reader.Read())
        {
            var item = new TestItem();
            item.ID = (int)reader[0];
            item.Name = (String)reader[1];
            item.BinaryData = (byte[])reader[2];
            itemsWithAdo.Add(item);
        }
        watch.Stop();
        Console.WriteLine("ExecuteReader Default : " + watch.ElapsedMilliseconds);
    }
}
Run Code Online (Sandbox Code Playgroud)

对于常规EF调用(.ToList()),分析似乎"正常"并且易于阅读:

ToList跟踪

在这里,我们发现使用秒表的时间为8.4秒(分析减慢了速度).我们还在呼叫路径上找到HitCount = 3500,这与测试中的3500行一致.在TDS解析器方面,事情开始变得更糟,因为我们读取了对TryReadByteArray()方法的118个353调用,这是缓冲循环发生的.(byte[]256kb 的平均每次呼叫33.8 )

对于这种async情况,它真的非常不同......首先,.ToListAsync()调用是在ThreadPool上安排的,然后等待.这里没什么了不起的.但是,现在,这async是ThreadPool 上的地狱:

ToListAsync地狱

首先,在第一种情况下,我们在整个呼叫路径上只有3500次点击计数,这里我们有118 371.此外,你必须想象我没有放在屏幕上的所有同步调用...

第二,在第一种情况下,我们对该TryReadByteArray()方法进行了"仅仅118 353"调用,这里我们有2 050 210个调用!这是它的17倍......(在大型1Mb阵列的测试中,它是160倍以上)

此外还有:

  • Task创建了120 000个实例
  • 727 519 Interlocked电话
  • 290 569 Monitor电话
  • 98 283个ExecutionContext实例,264 481个捕获
  • 208 733 SpinLock电话

我的猜测是缓冲是以异步方式(而不是一个好方法)进行的,并行任务试图从TDS读取数据.创建太多任务只是为了解析二进制数据.

作为初步结论,我们可以说Async很棒,EF6很棒,但EF6在其当前实现中的异步使用在性能方面,线程方面和CPU方面增加了一个主要的开销(12%的CPU使用率)ToList()案件和20%的ToListAsync情况下,工作时间长8到10倍......我在旧的i7 920上运行它.

在做一些测试时,我再次考虑这篇文章,并注意到我想念的东西:

"对于.Net 4.5中的新异步方法,它们的行为与同步方法完全相同,除了一个值得注意的例外:非顺序模式下的ReadAsync."

什么 ?!!!

所以我扩展我的基准测试,在常规/异步调用中包含Ado.Net,并使用CommandBehavior.SequentialAccess/ CommandBehavior.Default,这是一个很大的惊喜!:

与ado

我们与Ado.Net有完全相同的行为!捂脸......

我的最终结论是:EF 6实现中存在一个错误.当对包含列的表进行异步调用时,它应该切换CommandBehavior到.Ado.Net方面存在创建太多任务,减慢进程的问题.EF问题是它不应该使用Ado.Net.SequentialAccessbinary(max)

现在您知道不是使用EF6异步方法,而是最好以常规非异步方式调用EF,然后使用a TaskCompletionSource<T>以异步方式返回结果.

注1:由于一个可耻的错误,我编辑了我的帖子....我已经完成了我在网络上的第一次测试,而不是在本地,并且有限的带宽使结果失真.以下是更新的结果.

注2:我没有将我的测试扩展到其他用例(例如:nvarchar(max)有大量数据),但有可能发生相同的行为.

注3:这种情况通常ToList()是12%的CPU(我的CPU的1/8 = 1个逻辑核心).不寻常的是这种情况最多20%ToListAsync(),好像调度程序无法使用所有的Treads.这可能是由于创建了太多任务,或者可能是TDS解析器的瓶颈,我不知道......

  • 任何人都知道这是否仍然是EF Core的一个问题?我一直无法找到任何信息或基准. (6认同)
  • 可悲的是,GitHub上的问题已被关闭,建议不要与varbinary一起使用async.理论上,varbinary应该是异步最有意义的情况,因为在传输文件时线程将被阻塞更长时间.那么如果我们想在DB中保存二进制数据,我们现在该怎么办? (5认同)
  • 我在托管在github上的新EF代码存储库上打开了一个问题:https://github.com/aspnet/EntityFramework6/issues/88 (3认同)
  • 我在codeplex上打开了一个问题,希望他们能为此做些什么.https://entityframework.codeplex.com/workitem/2686 (2认同)
  • @AndrewLewis我没有背后的科学,但是我正在使用EF Core重复连接池超时,导致问题的两个查询是`.ToListAsync()`和`.CountAsync()`...给其他人发现此评论线程,[此查询](/sf/answers/869976481/)可能有所帮助.一帆风顺. (2认同)

Xen*_*o-D 8

因为几天前我得到了这个问题的链接,所以我决定发布一个小更新。我能够使用当前最新版本的 EF (6.4.0) 和 .NET Framework 4.7.2重现原始答案的结果。令人惊讶的是,这个问题从未得到改善。

.NET Framework 4.7.2 | EF 6.4.0 (Values in ms. Average of 10 runs)

non async : 3016
async : 20415
ExecuteReaderAsync SequentialAccess : 2780
ExecuteReaderAsync Default : 21061
ExecuteReader SequentialAccess : 3467
ExecuteReader Default : 3074
Run Code Online (Sandbox Code Playgroud)

这就引出了一个问题:dotnet 核心是否有改进?

我将原始答案中的代码复制到一个新的 dotnet core 3.1.3 项目并添加了 EF Core 3.1.3。结果是:

dotnet core 3.1.3 | EF Core 3.1.3 (Values in ms. Average of 10 runs)

non async : 2780
async : 6563
ExecuteReaderAsync SequentialAccess : 2593
ExecuteReaderAsync Default : 6679
ExecuteReader SequentialAccess : 2668
ExecuteReader Default : 2315
Run Code Online (Sandbox Code Playgroud)

令人惊讶的是,有很多改进。由于线程池被调用,似乎仍有一些时间滞后,但它比 .NET Framework 实现快 3 倍。

我希望这个答案可以帮助将来以这种方式发送的其他人。