aspnetcore: [.NET 6 Preview 4] Command is already in progress error in Npgsql library

Application Name: ComforDev OS: Windows 10 RS5 CPU: X64 .NET Build Number: 6.0.100-preview.4.21226.5

Verify Scenarios: 1). Windows 10 RS5 X64 + 6.0.100-preview.5.21222.19 - main branch: PASS 2). Windows 10 RS5 X64 + 6.0.100-preview.4.21226.5 - Preview 4 branch: Fail

Repro steps & source: Check at https://devdiv.visualstudio.com/DevDiv/_workitems/edit/1319505

Repro steps: 1)Restore DB by psql -d ComfortDev -U postgres -f ComfortDevdb.sql 2 Start Api by dotnet ComfortDevApp\API\ComfortDev.API.dll 3) Start Client Console app to connect to API by : running ComfortDevApp\Client\ConsoleApp1.exe

Expected Result: It should return db table record number

Actual Result:

Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware[1]
      An unhandled exception has occurred while executing the request.
      Npgsql.NpgsqlOperationInProgressException: A command is already in progress: SELECT t.id, t.question
      FROM test_questions AS t
         at Npgsql.NpgsqlConnector.<StartUserAction>g__DoStartUserAction|187_0(<>c__DisplayClass187_0& ) in Npgsql.dll:token 0x6000443+0x4c
         at Npgsql.NpgsqlConnector.StartUserAction(ConnectorState newState, NpgsqlCommand command) in Npgsql.dll:token 0x6000417+0x20
         at Npgsql.NpgsqlCommand.ExecuteReaderAsync(CommandBehavior behavior, Boolean async, CancellationToken cancellationToken) in Npgsql.dll:token 0x60002a7+0x11
         at Npgsql.NpgsqlCommand.ExecuteReader(CommandBehavior behavior) in Npgsql.dll:token 0x60002a4+0x16
         at Npgsql.NpgsqlCommand.ExecuteDbDataReader(CommandBehavior behavior) in Npgsql.dll:token 0x60002a1+0x0
         at System.Data.Common.DbCommand.ExecuteReader() in System.Data.Common.dll:token 0x60015c6+0x0
         at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReader(RelationalCommandParameterObject parameterObject) in Microsoft.EntityFrameworkCore.Relational.dll:token 0x6000304+0x7a
         at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1.Enumerator.InitializeReader(DbContext _, Boolean result) in Microsoft.EntityFrameworkCore.Relational.dll:token 0x6001121+0x50
         at Npgsql.EntityFrameworkCore.PostgreSQL.Storage.Internal.NpgsqlExecutionStrategy.Execute[TState,TResult](TState state, Func`3 operation, Func`3 verifySucceeded) in Npgsql.EntityFrameworkCore.PostgreSQL.dll:token 0x60001de+0x0
         at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1.Enumerator.MoveNext() in Microsoft.EntityFrameworkCore.Relational.dll:token 0x6001120+0x4a
         at Microsoft.EntityFrameworkCore.EntityFrameworkQueryableExtensions.Load[TSource](IQueryable`1 source) in Microsoft.EntityFrameworkCore.dll:token 0x6000203+0x13
         at Microsoft.EntityFrameworkCore.Internal.EntityFinder`1.Load(INavigation navigation, InternalEntityEntry entry) in Microsoft.EntityFrameworkCore.dll:token 0x6001326+0x2f
         at Microsoft.EntityFrameworkCore.ChangeTracking.NavigationEntry.Load() in Microsoft.EntityFrameworkCore.dll:token 0x6001724+0x8
         at Microsoft.EntityFrameworkCore.ChangeTracking.CollectionEntry.Load() in Microsoft.EntityFrameworkCore.dll:token 0x60016a9+0x6
         at Microsoft.EntityFrameworkCore.Internal.LazyLoader.Load(Object entity, String navigationName) in Microsoft.EntityFrameworkCore.dll:token 0x60013b2+0x24
         at Microsoft.EntityFrameworkCore.Proxies.Internal.LazyLoadingInterceptor.Intercept(IInvocation invocation) in Microsoft.EntityFrameworkCore.Proxies.dll:token 0x60000a3+0x7d
         at Castle.DynamicProxy.AbstractInvocation.Proceed() in Castle.Core.dll:token 0x600001c+0x50
         at Castle.Proxies.TestQuestionProxy.get_TestAnswers() in RefEmit_InMemoryManifestModule:token 0x6000051+0x24
         at System.Text.Json.Serialization.Metadata.JsonPropertyInfo`1.GetMemberAndWriteJson(Object obj, WriteStack& state, Utf8JsonWriter writer) in System.Text.Json.dll:token 0x60007b7+0x0
         at System.Text.Json.Serialization.Converters.ObjectDefaultConverter`1.OnTryWrite(Utf8JsonWriter writer, T value, JsonSerializerOptions options, WriteStack& state) in System.Text.Json.dll:token 0x60008d8+0x199
         at System.Text.Json.Serialization.JsonConverter`1.TryWrite(Utf8JsonWriter writer, T& value, JsonSerializerOptions options, WriteStack& state) in System.Text.Json.dll:token 0x60006f6+0x206
         at System.Text.Json.Serialization.Converters.IAsyncEnumerableOfTConverter`2.OnWriteResume(Utf8JsonWriter writer, TAsyncEnumerable value, JsonSerializerOptions options, WriteStack& state) in System.Text.Json.dll:token 0x600084c+0xb4
         at System.Text.Json.Serialization.Converters.IEnumerableDefaultConverter`2.OnTryWrite(Utf8JsonWriter writer, TCollection value, JsonSerializerOptions options, WriteStack& state) in System.Text.Json.dll:token 0x600087a+0x86
         at System.Text.Json.Serialization.Converters.IAsyncEnumerableOfTConverter`2.OnTryWrite(Utf8JsonWriter writer, TAsyncEnumerable value, JsonSerializerOptions options, WriteStack& state) in System.Text.Json.dll:token 0x600084b+0x14
         at System.Text.Json.Serialization.JsonConverter`1.TryWrite(Utf8JsonWriter writer, T& value, JsonSerializerOptions options, WriteStack& state) in System.Text.Json.dll:token 0x60006f6+0x206
         at System.Text.Json.Serialization.JsonConverter`1.WriteCore(Utf8JsonWriter writer, T& value, JsonSerializerOptions options, WriteStack& state) in System.Text.Json.dll:token 0x60006e1+0x0
         at System.Text.Json.Serialization.JsonConverter`1.WriteCoreAsObject(Utf8JsonWriter writer, Object value, JsonSerializerOptions options, WriteStack& state) in System.Text.Json.dll:token 0x60006e0+0x49
         at System.Text.Json.JsonSerializer.WriteCore[TValue](JsonConverter jsonConverter, Utf8JsonWriter writer, TValue& value, JsonSerializerOptions options, WriteStack& state) in System.Text.Json.dll:token 0x600035a+0x18
         at System.Text.Json.JsonSerializer.WriteAsyncCore[TValue](Stream utf8Json, TValue value, JsonTypeInfo jsonTypeInfo, CancellationToken cancellationToken) in System.Text.Json.dll:token 0x6000364+0xd4
         at System.Text.Json.JsonSerializer.WriteAsyncCore[TValue](Stream utf8Json, TValue value, JsonTypeInfo jsonTypeInfo, CancellationToken cancellationToken) in System.Text.Json.dll:token 0x6000364+0x1b5
         at System.Text.Json.JsonSerializer.WriteAsyncCore[TValue](Stream utf8Json, TValue value, JsonTypeInfo jsonTypeInfo, CancellationToken cancellationToken) in System.Text.Json.dll:token 0x6000364+0x38b
         at Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonOutputFormatter.WriteResponseBodyAsync(OutputFormatterWriteContext context, Encoding selectedEncoding) in Microsoft.AspNetCore.Mvc.Core.dll:token 0x6000b07+0x132
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeNextResultFilterAsync>g__Awaited|30_0[TFilter,TFilterAsync](ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted) in Microsoft.AspNetCore.Mvc.Core.dll:token 0x6000a83+0x6a
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Rethrow(ResultExecutedContextSealed context) in Microsoft.AspNetCore.Mvc.Core.dll:token 0x6000a76+0x15
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.ResultNext[TFilter,TFilterAsync](State& next, Scope& scope, Object& state, Boolean& isCompleted) in Microsoft.AspNetCore.Mvc.Core.dll:token 0x6000a71+0x3dc
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeResultFilters>g__Awaited|28_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted) in Microsoft.AspNetCore.Mvc.Core.dll:token 0x6000a82+0x6e
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeFilterPipelineAsync>g__Awaited|20_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted) in Microsoft.AspNetCore.Mvc.Core.dll:token 0x6000a7b+0x65
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Logged|17_1(ResourceInvoker invoker) in Microsoft.AspNetCore.Mvc.Core.dll:token 0x6000a78+0x172
         at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Logged|17_1(ResourceInvoker invoker) in Microsoft.AspNetCore.Mvc.Core.dll:token 0x6000a78+0x21d
         at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger) in Microsoft.AspNetCore.Routing.dll:token 0x60000aa+0x5e
         at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context) in Microsoft.AspNetCore.Authorization.Policy.dll:token 0x600000b+0x16b
         at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(HttpContext context) in Microsoft.AspNetCore.Authentication.dll:token 0x6000044+0x384
         at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(HttpContext context) in Microsoft.AspNetCore.Diagnostics.dll:token 0x60000aa+0x82
warn: Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware[2]
      The response has already started, the error page middleware will not be executed.

Findings : This issue occurs when UseLazyLoadingProxies is enabled. We couldn’t repro this issue when using Sql Server, this could only be in postgres.

In Api, we are trying to get data from a table and also its related data with LazyLoading enabled ,

   public IEnumerable<TestQuestion> GetTest()

        {
            return database.TestQuestions.GetAll();
        }

In Client Side , we call API :

private static async Task<IEnumerable<Question>> GetDataAsnyc()

{
try
{
using var client = new HttpClient();
var streamTask = client.GetStreamAsync("https://localhost:5001/api/test");
var serializer = new DataContractJsonSerializer(typeof(IEnumerable<Question>));
var questions = serializer.ReadObject(await streamTask) as IEnumerable<Question>;
return questions;
}
catch (Exception ex)
{
   return null;
}
}

@dotnet-actwx-bot @dotnet/compat

About this issue

Original URL
State: closed
Created 3 years ago
Comments: 24 (19 by maintainers)

Most upvoted comments

In 5.0, MVC buffered IAsyncEnumerable instances, effectively calling ToListAsync() on the user’s behalf. At that point, it would exhaust the enumerable before beginning to serialize individual items that would result in lazy loading. In 6.0-p4, the buffering was removed in lieu of directly invoking the serializer. This now results in the simultaneous enumeration of the IAsyncEnumerable as well as accessing the lazy loaded property as part of the serialization of individual items, resulting in this issue.

If we think this was a problematic pattern to start with, I think documenting the breaking behavior change and providing users correct guidance on how to do it right way would be the way to go.

Btw, it’s really cool we’re discovering all these fun issues as part of release validation. 👍🏽

pranavkm on Apr 29, 2021

Breaking change announcement: https://github.com/aspnet/Announcements/issues/463

pranavkm on May 6, 2021

I think this is something ASP.NET should document as a breaking change. The lazy-loading case here is really an anti-pattern (as I mentioned above) so this failure is perhaps not very interesting. However, changing where streaming happens means that the DbContext is now used at a later point it was before. This will break if the context is disposed after where it was used before, but before where it is used now. This typically isn’t a problem when the context is scoped to the request, but more and more people are using DbContextFactory, in which case the context is often disposed sooner. Likely people will now need to do their own buffering in these cases, whereas before ASP.NET was doing it for them.

ajcvickers on Apr 29, 2021

@pranavkm then yeah, makes sense and sounds pretty much like what @ajcvickers described above; the thing is less related to sync/async and more to whether ASP.NET buffers everything before the JSON serializer starts to drill into the object graph (and triggers additional queries because of lazy loading).

Removing the buffering behavior sounds like the right thing, and FWIW we don’t recommend using lazy loading in this way (or at all, actually…), so IMHO documenting this as a breaking change is the way to go. @ajcvickers what do you think?

roji on Apr 29, 2021

One additional note - the Npgsql EF Core provider is managed in this repo, while the ADO.NET provider is managed in this one. Neither are part of System.Data.

roji on Apr 27, 2021

@jiangzeng01 I wasn’t able to reproduce the error with the repro, with the following steps:

Copy the application source to a local drive (from ComforDev2\ComfortDev)
Create a blank database and apply ComfortDevdb.sql to it (from ComfortDevApp\DB)
Modify ComfortDev.Common\Secret.cs to make the connection string point to the populated database
Install .NET SDK 6.0.100-preview.4.21226.5 with dotnet-install.ps1
Execute dotnet run under ComfortDev\ComfortDev.API
Access https://localhost:5001/api/test with the browser (note that the source code for the client applicaiton does seem to be provided above, so I just accessed the API directly)

Result: I get a proper JSON response with all the data.

Note that the error you’re seeing - a command is already in progress - is quite common, and especially when using lazy loading. The following snippet demonstrates it well:

foreach (var blog in context.Blogs)
{
    foreach (var post in blog.Posts)
    {
        Console.WriteLine(post.Name);     
    }
}

In this code snippet, a command is started to fetch all the blogs. Then, before that command completes, another command is started to fetch the posts for a given blog, but two commands aren’t allowed concurrently in Npgsql. This code will work on SQL Server if MARS is enabled on your connection string, which could explain why your code works on SQL Server but not on PostgreSQL. A possible workaround is to add .ToList() after context.Blogs - this makes EF Core load all blogs into memory and close the first command before proceeding to load posts.

Other unrelated comments:

The API project currently targets netcoreapp3.0, which has reached its end of life, and is not supported. It’s strongly recommended to upgrade to at least netcoreapp3.1.
Having a Secrets.cs file is extremely problematic from a security point of view, and can very easily lead to secret leak. You probably want to look at better secret management (this can be a good starting point).

roji on Apr 27, 2021