c# - foreign - La operación asincrónica de Entity Framework tarda diez veces más en completarse

key data annotation c#

Question

Tengo un sitio MVC que usa Entity Framework 6 para manejar la base de datos, y he estado experimentando con cambiarlo para que todo se ejecute como controladores asíncronos y las llamadas a la base de datos se ejecuten como sus contrapartes asíncronas (por ejemplo, ToListAsync () en lugar de ToList ())

El problema que tengo es que simplemente cambiar mis consultas a asíncrono ha provocado que sean increíblemente lentas.

El siguiente código obtiene una colección de objetos "Álbum" de mi contexto de datos y se traduce en una unión de base de datos bastante simple:

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

Aquí está el SQL que se crea:

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

Tal como están las cosas, no es una consulta enormemente complicada, pero el servidor SQL tarda casi 6 segundos en ejecutarla. SQL Server Profiler informa que tarda 5742 ms en completarse.

Si cambio mi código a:

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

Luego se genera exactamente el mismo SQL, pero esto se ejecuta en solo 474 ms según el SQL Server Profiler.

La base de datos tiene alrededor de 3500 filas en la tabla "Álbumes", que en realidad no son muchas, y tiene un índice en la columna "Artist_ID", por lo que debería ser bastante rápido.

Sé que async tiene gastos generales, ¡pero hacer que las cosas vayan diez veces más lento me parece un poco caro! ¿Dónde me estoy equivocando aquí?

Answer 1

Encontré esta pregunta muy interesante, especialmente porque estoy usando async todas partes con Ado.Net y EF 6. Esperaba que alguien me diera una explicación, pero no sucedió. Así que intenté reproducir este problema de mi lado. Espero que algunos de ustedes encuentren esto interesante.

Primeras buenas noticias: lo reproduje :) Y la diferencia es enorme. Con un factor 8 ...

Primero sospechaba algo relacionado con CommandBehavior , ya que leí un artículo interesante sobre async con Ado, que decía esto:

"Dado que el modo de acceso no secuencial tiene que almacenar los datos para toda la fila, puede causar problemas si está leyendo una columna grande del servidor (como varbinary (MAX), varchar (MAX), nvarchar (MAX) o XML ) ".

Sospechaba que las llamadas a ToList() eran CommandBehavior.SequentialAccess y las asíncronas eran CommandBehavior.Default (no secuencial, lo que puede causar problemas). Así que descargué las fuentes de EF6 y puse puntos de interrupción en todas partes (donde CommandBehavior usó, por supuesto).

Resultado: nada . Todas las llamadas se realizan con CommandBehavior.Default ... Así que traté de ingresar al código EF para entender lo que sucede ... y ... ooouch ... Nunca veo un código tan delegante, todo parece perezoso ejecutado ...

Así que traté de hacer algunos perfiles para entender lo que sucede ...

Y creo que tengo algo ...

Aquí está el modelo para crear la tabla que comparé, con 3500 líneas dentro de ella y datos aleatorios de 256 Kb en cada 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; }
}

Y aquí está el código que usé para crear los datos de prueba, y el punto de referencia 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);
    }
}

Para la llamada EF normal ( .ToList() ), el perfil parece "normal" y es fácil de leer:

Aquí encontramos los 8.4 segundos que tenemos con el cronómetro (el perfil ralentiza los resultados). También encontramos HitCount = 3500 a lo largo de la ruta de llamada, que es consistente con las 3500 líneas en la prueba. En el lado del analizador TDS, las cosas comienzan a empeorar ya que leemos 118 353 llamadas en el método TryReadByteArray() , que es donde ocurre el bucle de almacenamiento en búfer. (un promedio de 33.8 llamadas por cada byte[] de 256kb)

Para el caso async , es realmente muy diferente ... Primero, la llamada .ToListAsync() se programa en el ThreadPool y luego se espera. Nada asombroso aquí. Pero, ahora, aquí está el infierno async en ThreadPool:

Primero, en el primer caso, teníamos solo 3500 recuentos de visitas a lo largo de la ruta de llamada completa, aquí tenemos 118 371. Además, debes imaginar todas las llamadas de sincronización que no puse en la captura de pantalla ...

Segundo, en el primer caso, teníamos "solo 118 353" llamadas al método TryReadByteArray() , ¡aquí tenemos 2 050 210 llamadas! Es 17 veces más ... (en una prueba con una gran matriz de 1Mb, es 160 veces más)

Además hay:

• 120 000 instancias de Task creadas
• Interlocked llamadas Interlocked
• 290 569 Monitor llamadas
• ExecutionContext instancias de ExecutionContext , con 264481 capturas
• 208 733 llamadas SpinLock

Supongo que el almacenamiento en búfer se realiza de forma asíncrona (y no es buena), con tareas paralelas que intentan leer datos del TDS. Se crean demasiadas tareas solo para analizar los datos binarios.

Como conclusión preliminar, podemos decir que Async es excelente, EF6 es excelente, pero los usos de EF6 de asíncrono en su implementación actual agrega una sobrecarga importante, en el lado del rendimiento, el lado de subprocesos y el lado de la CPU (12% de uso de CPU en el ToList() y 20% en el caso ToListAsync para un trabajo de 8 a 10 veces más largo ... lo ejecuto en un viejo i7 920).

Mientras hacía algunas pruebas, estaba pensando en este artículo nuevamente y noto algo que extraño:

"Para los nuevos métodos asincrónicos en .Net 4.5, su comportamiento es exactamente el mismo que con los métodos síncronos, excepto por una notable excepción: ReadAsync en modo no secuencial".

Qué ?!!!

Así que extiendo mis puntos de referencia para incluir Ado.Net en llamadas regulares / asíncronas, y con CommandBehavior.SequentialAccess / CommandBehavior.Default , ¡y aquí hay una gran sorpresa! :

Tenemos exactamente el mismo comportamiento con Ado.Net !!! Facepalm ...

Mi conclusión definitiva es : hay un error en la implementación de EF 6. Debe alternar CommandBehavior a SequentialAccess cuando se realiza una llamada asincrónica sobre una tabla que contiene una columna binary(max) . El problema de crear demasiadas Tareas, ralentizar el proceso, está en el lado de Ado.Net. El problema de EF es que no usa Ado.Net como debería.

Ahora sabe que en lugar de utilizar los métodos asíncronos EF6, será mejor que llame a EF de una manera no asíncrona regular y luego use un TaskCompletionSource<T> para devolver el resultado de forma asíncrona.

Nota 1: edité mi publicación debido a un error vergonzoso ... Hice mi primera prueba en la red, no localmente, y el ancho de banda limitado ha distorsionado los resultados. Aquí están los resultados actualizados.

Nota 2: No extendí mi prueba a otros casos de uso (ej: nvarchar(max) con muchos datos), pero hay posibilidades de que ocurra el mismo comportamiento.

Nota 3: Algo habitual para el caso ToList() es el 12% de CPU (1/8 de mi CPU = 1 núcleo lógico). Algo inusual es el máximo del 20% para el caso ToListAsync() , como si el Programador no pudiera usar todos los Treads. Probablemente se deba a la demasiada Tarea creada, o tal vez un cuello de botella en el analizador TDS, no lo sé ...