ToListAsync on a query with thousands of entries inside a "where contains" statement requires MARS=True (inside Docker container)

[Cogax]

ToListAsync() thorws Exceptions on a big query

Recently, we had a production issue in one of our services. We managed to reproduce the issue and found out, that IQueryable<>.ToListAsync() failes on a .Where(x => myIds.Contains(x.Id)) query, when myIds contains thousands (> ~3500) of entries. This behavior could be reproduced on a Azure Sql Database with MultipleActiveResultSets=False in the connection string. Furthermore, this behavior only occures on Linux (tested inside a Docker container). If we replace .ToListAsync() with .ToList(), the error is gone. On a dockerized MSSQL Server 2019 the error also won't occur.

We tested different setups with the code bellow. Here are the results (green = OK, red = NOK)

Hint: We needMultipleActiveResultSets set to False because we had this issue, which isn't resolved yet: dotnet/SqlClient#422

Code

The following listings will show our project where we reproduced the bug. Notice, that we are using docker-compose and an Azure Sql Database.

• With a line in Program.cs (var connectionString = azure;), the database (local or azure) can be controlled.
• With a line in Program.cs (Enumerable.Range(1, 4000) ) the amount of entries can be controlled.
• To Run it on WIndows, you can start it from within Visual Studio.
• Do Run it on Linux (Docker) you can run it with docker-compose up --build

EfCoreBug.csproj File:

<Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFramework>netcoreapp3.1</TargetFramework>
  </PropertyGroup>
  <ItemGroup>
    <PackageReference Include="Microsoft.EntityFrameworkCore" Version="3.1.10" />
    <PackageReference Include="Microsoft.EntityFrameworkCore.SqlServer" Version="3.1.10" />
  </ItemGroup>
</Project>

Program.cs File:

public class Program
{
    public static async Task Main(string[] args)
    {
        var local = Environment.GetEnvironmentVariable("ConnectionStringLocal")
            ?? "Data Source=localhost,1433; Database=MyDb; multipleactiveresultsets=False; User Id=sa; Password=Top-Secret; Connection Timeout=60; ConnectRetryCount=8; ConnectRetryInterval=2";

        var azure = Environment.GetEnvironmentVariable("ConnectionStringAzure")
            ?? "Data Source=***.database.windows.net; Database=MyDb; persist security info=True; user id=***; password=***; multipleactiveresultsets=False";

        var connectionString = azure;

        await EnsureDatabaseExists(connectionString);
        await RecreateTable(connectionString);

        var context = GetDbContext(connectionString);

        var foos = Enumerable.Range(1, 4000)
            .OrderBy(x => x)
            .Select(x => new Foo {Value = x})
            .ToList();

        await context.Foo.AddRangeAsync(foos);
        await context.SaveChangesAsync();

        if (context.Foo.Count() != foos.Count)
            throw new Exception("not fully saved");

        var fooIds = foos.Select(x => x.Id).ToList();
        var loadedFoos = context.Foo
            .Where(x => fooIds.Contains(x.Id))
            .ToList();

        if(loadedFoos.Count != foos.Count)
            throw new Exception("not fully loaded");

        Console.WriteLine("Fully Loaded! OK!");
    }

    private static MyContext GetDbContext(string connectionString)
    {
        var options = new DbContextOptionsBuilder<MyContext>()
            .UseSqlServer(
                connectionString,
                sqlServerOptionsAction => sqlServerOptionsAction
                    .EnableRetryOnFailure()
                    .CommandTimeout(3600))
            .EnableSensitiveDataLogging()
            .Options;

        var context = new MyContext(options);
        return context;
    }

    public static async Task EnsureDatabaseExists(string connectionString)
    {
        var builder = new SqlConnectionStringBuilder(connectionString);
        var dbName = builder.InitialCatalog;

        Console.WriteLine($"Ensuring Database [{dbName}] exists...");

        builder.InitialCatalog = "master";

        await using var connection = new SqlConnection(builder.ConnectionString);
        await connection.OpenAsync();

        var query = connection.CreateCommand();

        query.CommandText = $"SELECT COUNT(*) FROM sys.databases WHERE NAME = '{dbName}'";

        var result = await query.ExecuteScalarAsync();

        if ((int)result != 0)
        {
            Console.WriteLine($"Database [{dbName}] already exists!");
            return;
        }

        Console.WriteLine($"Creating Database [{dbName}].");

        await using var cmd = connection.CreateCommand();
        cmd.CommandText = $"CREATE DATABASE [{dbName}]";
        await cmd.ExecuteNonQueryAsync();
    }

    public static async Task RecreateTable(string connectionString)
    {
        await using var connection = new SqlConnection(connectionString);
        await connection.OpenAsync();
        await using var cmd = connection.CreateCommand();
        cmd.CommandText = 
            $@"DROP TABLE IF EXISTS Foo; 
                CREATE TABLE Foo (Id [BIGINT] NOT NULL identity(1,1) primary key, Value [BIGINT] NOT NULL);";
        await cmd.ExecuteNonQueryAsync();
    }
}

public class MyContext : DbContext
{
    public DbSet<Foo> Foo { get; set; }
    public MyContext(DbContextOptions<MyContext> options) : base(options)
    { }
}

public class Foo
{
    [Key]
    [DatabaseGenerated(DatabaseGeneratedOption.Identity)]
    public long Id { get; set; }
    public long Value { get; set; }
}

Dockerfile

FROM mcr.microsoft.com/dotnet/core/sdk:3.1 AS builder
WORKDIR /app
COPY ./*.csproj ./
RUN dotnet restore
COPY ./ ./
RUN dotnet publish -c Release -o out
FROM mcr.microsoft.com/dotnet/core/aspnet:3.1 as runtime
COPY --from=builder ["/app/out", "./"]
ENTRYPOINT ["dotnet", "EfCoreBug.dll"]

docker-compose.yml

version: "2.4"
services:
  db:
    image: mcr.microsoft.com/mssql/server:2019-CU5-ubuntu-16.04
    ports:
      - 1433:1433
    environment:
      ACCEPT_EULA: "Y"
      SA_PASSWORD: Top-Secret
      MSSQL_PID: Developer
    healthcheck:
      test: /opt/mssql-tools/bin/sqlcmd -U sa -P Top-Secret || exit 1
      interval: 2s
      timeout: 2s
      retries: 10
      start_period: 15s
  test:
    build:
      context: .
      dockerfile: Dockerfile
    environment:
     - ConnectionStringAzure=Data Source=***.database.windows.net; Database=MyDb; persist security info=True; user id=***; password=***; multipleactiveresultsets=False;
     - ConnectionStringLocal=Data Source=db,1433; Database=MyDb; User Id=sa; Password=Top-Secret; Connection Timeout=60; ConnectRetryCount=8; ConnectRetryInterval=2; multipleactiveresultsets=False;
    depends_on:
      db:
        condition: service_healthy

Two different Exceptions

The code above will reproduce the following exception, when running the failing scenario:

Unhandled exception. System.InvalidOperationException: Invalid operation. The connection is closed.
   at Microsoft.Data.SqlClient.SqlCommand.<>c.<ExecuteDbDataReaderAsync>b__164_0(Task`1 result)
   at System.Threading.Tasks.ContinuationResultTaskFromResultTask`2.InnerInvoke()
   at System.Threading.Tasks.Task.<>c.<.cctor>b__274_0(Object obj)
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location where exception was thrown ---
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot, Thread threadPoolThread)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReaderAsync(RelationalCommandParameterObject parameterObject, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReaderAsync(RelationalCommandParameterObject parameterObject, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReaderAsync(RelationalCommandParameterObject parameterObject, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1.AsyncEnumerator.InitializeReaderAsync(DbContext _, Boolean result, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Storage.ExecutionStrategy.ExecuteImplementationAsync[TState,TResult](Func`4 operation, Func`4 verifySucceeded, TState state, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Storage.ExecutionStrategy.ExecuteImplementationAsync[TState,TResult](Func`4 operation, Func`4 verifySucceeded, TState state, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1.AsyncEnumerator.MoveNextAsync()
   at Microsoft.EntityFrameworkCore.EntityFrameworkQueryableExtensions.ToListAsync[TSource](IQueryable`1 source, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.EntityFrameworkQueryableExtensions.ToListAsync[TSource](IQueryable`1 source, CancellationToken cancellationToken)
   at EfCoreBug.Program.Main(String[] args) in /app/Program.cs:line 41
   at EfCoreBug.Program.<Main>(String[] args)

Another Exception we sometimes get on the production system is the following:

    Test method ***.IntegrationTests.IntegrationTests.Test.DoTest threw exception:
 Microsoft.Data.SqlClient.SqlException: A transport-level error has occurred when sending the request to the server. (provider: TCP Provider, error: 35 - An internal exception was caught) ---> System.NotSupportedException:  The WriteAsync method cannot be called when another write operation is pending.
   Stack Trace:
       at System.Net.Security.SslStream.WriteAsyncInternal[TWriteAdapter](TWriteAdapter writeAdapter, ReadOnlyMemory`1 buffer)
    at Microsoft.Data.SqlClient.SNI.SNIPacket.WriteToStreamAsync(Stream stream, SNIAsyncCallback callback, SNIProviders provider)
 --- End of inner exception stack trace ---
     at Microsoft.Data.SqlClient.SqlCommand.<>c.<ExecuteDbDataReaderAsync>b__169_0(Task`1 result)
    at System.Threading.Tasks.ContinuationResultTaskFromResultTask`2.InnerInvoke()
    at System.Threading.Tasks.Task.<>c.<.cctor>b__274_0(Object obj)
    at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
 --- End of stack trace from previous location where exception was thrown ---
    at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
    at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot, Thread threadPoolThread)
 --- End of stack trace from previous location where exception was thrown ---
    at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReaderAsync(RelationalCommandParameterObject parameterObject, CancellationToken cancellationToken)
    at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReaderAsync(RelationalCommandParameterObject parameterObject, CancellationToken cancellationToken)
    at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReaderAsync(RelationalCommandParameterObject parameterObject, CancellationToken cancellationToken)
    at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1.AsyncEnumerator.InitializeReaderAsync(DbContext _, Boolean result, CancellationToken cancellationToken)
    at Microsoft.EntityFrameworkCore.Storage.ExecutionStrategy.ExecuteImplementationAsync[TState,TResult](Func`4 operation, Func`4 verifySucceeded, TState state, CancellationToken cancellationToken)
    at Microsoft.EntityFrameworkCore.Storage.ExecutionStrategy.ExecuteImplementationAsync[TState,TResult](Func`4 operation, Func`4 verifySucceeded, TState state, CancellationToken cancellationToken)
    at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1.AsyncEnumerator.MoveNextAsync()
    at Microsoft.EntityFrameworkCore.EntityFrameworkQueryableExtensions.ToListAsync[TSource](IQueryable`1 source, CancellationToken cancellationToken)
    at Microsoft.EntityFrameworkCore.EntityFrameworkQueryableExtensions.ToListAsync[TSource](IQueryable`1 source, CancellationToken cancellationToken)
    at ***.IntegrationTests.IntegrationTests.Test.DoTest() in /src/***.IntegrationTests/IntegrationTests/Test.cs:line 25
    at Microsoft.VisualStudio.TestPlatform.MSTestAdapter.PlatformServices.ThreadOperations.ExecuteWithAbortSafety(Action action)

Include provider and version information

EF Core version: 3.1.10
Database provider: Microsoft.EntityFrameworkCore.SqlServer 3.1.10
Target framework: netcoreapp3.1
Operating system: WIndows / Linux (Docker)
IDE: Visual Studio 2019 16.8.1

[smitpatel]

#13617

[Cogax]

Seems to be an exact duplicate of #14737. As metioned in that issue, I get the same error also with non async methods. So, ToList() with 100k entries results in this exception:

 Unhandled exception. Microsoft.Data.SqlClient.SqlException (0x80131904): The query processor ran out of internal resources and could not produce a query plan. This is a rare event and only expected for extremely complex queries or queries that reference a very large number of tables or partitions. Please simplify the query. If you believe you have received this message in error, contact Customer Support Services for more information.
    at Microsoft.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
    at Microsoft.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
    at Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
    at Microsoft.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
    at Microsoft.Data.SqlClient.SqlDataReader.TryConsumeMetaData()
    at Microsoft.Data.SqlClient.SqlDataReader.get_MetaData()
    at Microsoft.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted)
    at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean isAsync, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest)
    at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry, String method)
    at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
    at Microsoft.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior)
    at Microsoft.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior)
    at System.Data.Common.DbCommand.ExecuteReader()
    at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReader(RelationalCommandParameterObject parameterObject)
    at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1.Enumerator.InitializeReader(DbContext _, Boolean result)
    at Microsoft.EntityFrameworkCore.Storage.ExecutionStrategy.ExecuteImplementation[TState,TResult](Func`3 operation, Func`3 verifySucceeded, TState state)
    at Microsoft.EntityFrameworkCore.Storage.ExecutionStrategy.Execute[TState,TResult](TState state, Func`3 operation, Func`3 verifySucceeded)
    at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1.Enumerator.MoveNext()
    at System.Collections.Generic.List`1..ctor(IEnumerable`1 collection)
    at System.Linq.Enumerable.ToList[TSource](IEnumerable`1 source)
    at EfCoreBug.Program.Main(String[] args) in /app/Program.cs:line 44
    at EfCoreBug.Program.<Main>(String[] args)
 ClientConnectionId:cf680a7f-f622-4bf7-a112-b558962284f3
 Error Number:8623,State:1,Class:16

But there seem to be not an exact solution. I will now try to implement "workarounds" mentioned in #13617.