Асинхронная операция Entity Framework занимает в десять раз больше времени

У меня есть сайт MVC, использующий Entity Framework 6 для обработки базы данных, и я экспериментировал с его изменением, чтобы все работало как асинхронные контроллеры, а вызовы базы данных выполнялись как их асинхронные аналоги (например, ToListAsync () вместо ToList ())

Проблема, с которой я столкнулся, заключается в том, что простое изменение моих запросов на асинхронные привело к тому, что они стали невероятно медленными.

Следующий код получает коллекцию объектов «Альбом» из моего контекста данных и преобразуется в довольно простое соединение с базой данных:

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

Вот созданный 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

По сути, это не очень сложный запрос, но SQL-серверу требуется почти 6 секунд для его выполнения. SQL Server Profiler сообщает, что для завершения требуется 5742 мс.

Если я изменю свой код на:

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

Затем генерируется точно такой же SQL, но, по данным SQL Server Profiler, он выполняется всего за 474 мс.

База данных содержит около 3500 строк в таблице «Альбомы», что на самом деле не очень много, и имеет индекс в столбце «Artist_ID», так что это должно быть довольно быстро.

Я знаю, что у асинхронного режима есть накладные расходы, но заставить работать в десять раз медленнее мне кажется немного крутым! Где я здесь ошибаюсь?

Мне этот вопрос asyncпоказался очень интересным, особенно потому, что я везде использую Ado.Net и EF 6. Я надеялся, что кто-то даст объяснение по этому вопросу, но этого не произошло. Поэтому я попытался воспроизвести эту проблему на своей стороне. Я надеюсь, что некоторым из вас это будет интересно.

Первая хорошая новость: воспроизвел :) А разница колоссальная. С коэффициентом 8 ...

Сначала я подозревал, что с чем-то связан CommandBehavior, так как прочитал интересную статью о asyncАдо, в которой говорилось следующее:

"Поскольку режим непоследовательного доступа должен хранить данные для всей строки, это может вызвать проблемы, если вы читаете большой столбец с сервера (например, varbinary (MAX), varchar (MAX), nvarchar (MAX) или XML). ). "

Я подозревал, что ToList()вызовы CommandBehavior.SequentialAccessи асинхронные вызовы CommandBehavior.Default(непоследовательные, что может вызвать проблемы). Поэтому я скачал исходники EF6 и повсюду ставил точки останова ( CommandBehaviorконечно, там, где они использовались).

Результат: ничего . Все вызовы выполняются с помощью CommandBehavior.Default... Итак, я попытался войти в код EF, чтобы понять, что происходит ... и ... ooouch ... Я никогда не видел такого кода делегирования, все кажется ленивым ...

Итак, я попытался провести профилирование, чтобы понять, что происходит ...

И я думаю, что у меня что-то есть ...

Вот модель для создания таблицы, которую я тестировал, с 3500 строками внутри и 256 КБ случайных данных в каждой 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; }
}

А вот код, который я использовал для создания тестовых данных и тестирования 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);
    }
}

Для обычного вызова EF ( .ToList()) профилирование кажется "нормальным" и его легко читать:

Здесь мы находим 8,4 секунды, которые у нас есть с секундомером (профилирование замедляет производительность). Мы также находим HitCount = 3500 вдоль пути вызова, что соответствует 3500 строкам в тесте. На стороне парсера TDS все стало хуже, так как мы прочитали 118 353 вызовов TryReadByteArray()метода, которые были в цикле буферизации. (в среднем 33,8 звонка на каждый byte[]из 256кб)

Для asyncслучая это действительно совсем другое .... Сначала .ToListAsync()вызов запланирован на ThreadPool, а затем ожидается. Здесь ничего удивительного. Но вот, asyncчерт возьми, ThreadPool:

Во-первых, в первом случае у нас было всего 3500 счетчиков совпадений по всему пути вызова, а здесь 118 371. Более того, вы должны представить себе все вызовы синхронизации, которые я не использовал на снимке экрана ...

Во-вторых, в первом случае у нас было «всего 118 353» вызовов TryReadByteArray()метода, здесь у нас 2 050 210 вызовов! Это в 17 раз больше ... (на тесте с большим массивом в 1Мб больше в 160 раз)

Кроме того, есть:

• TaskСоздано 120000 экземпляров
• 727 519 Interlockedзвонков
• 290 569 Monitorзвонков
• 98 283 ExecutionContextэкземпляра, 264 481 захват
• 208733 SpinLockзвонка

Я предполагаю, что буферизация выполняется асинхронно (и не очень хорошо), когда параллельные задачи пытаются читать данные из TDS. Слишком много задач создано только для анализа двоичных данных.

В качестве предварительного вывода мы можем сказать, что Async великолепен, EF6 великолепен, но использование асинхронного режима EF6 в его текущей реализации приводит к значительным накладным расходам со стороны производительности, со стороны потоков и со стороны ЦП (12% использования ЦП в ToList()case и 20% в ToListAsyncслучае для работы в 8-10 раз дольше ... Я запускал его на старом i7 920).

Выполняя некоторые тесты, я снова думал об этой статье и замечаю то, что мне не хватает:

«Для новых асинхронных методов в .Net 4.5 их поведение точно такое же, как и для синхронных методов, за исключением одного примечательного исключения: ReadAsync в непоследовательном режиме».

Какие ?!!!

Поэтому я расширяю свои тесты, чтобы включить Ado.Net в обычный / асинхронный вызов и с CommandBehavior.SequentialAccess/ CommandBehavior.Default, и вот большой сюрприз! :

То же самое и с Ado.Net !!! Facepalm ...

Мой окончательный вывод : в реализации EF 6 есть ошибка. Он должен переключить , CommandBehaviorчтобы , SequentialAccessкогда асинхронный вызов выполняется над столом , содержащей binary(max)колонку. Проблема создания слишком большого количества Задач, замедляющего процесс, находится на стороне Ado.Net. Проблема EF в том, что он не использует Ado.Net должным образом.

Теперь вы знаете, что вместо использования асинхронных методов EF6 вам лучше вызвать EF обычным неасинхронным способом, а затем использовать a TaskCompletionSource<T>для возврата результата асинхронным способом.

Примечание 1: я отредактировал свой пост из-за постыдной ошибки .... Я провел свой первый тест по сети, а не локально, и ограниченная пропускная способность исказила результаты. Вот обновленные результаты.

Примечание 2: я не распространял свой тест на другие варианты использования (например, nvarchar(max)с большим количеством данных), но есть вероятность, что произойдет то же самое.

Примечание 3: что-то обычное для этого ToList()случая - это 12% ЦП (1/8 моего ЦП = 1 логическое ядро). Что-то необычное - это максимум 20% для ToListAsync()случая, как будто планировщик не может использовать все ступени. Вероятно, это из-за слишком большого количества созданных задач или, может быть, из-за узкого места в парсере TDS, я не знаю ...

Поскольку пару дней назад я получил ссылку на этот вопрос, я решил опубликовать небольшое обновление. Мне удалось воспроизвести результаты исходного ответа, используя новейшую на данный момент версию 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

Возникает вопрос: есть ли улучшения в ядре 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

На удивление много улучшений. По-прежнему кажется, что некоторое время задерживается, потому что вызывается пул потоков, но он примерно в 3 раза быстрее, чем реализация .NET Framework.

Я надеюсь, что этот ответ поможет другим людям, которые будут так поступать в будущем.