efcore.pg: NpgsqlOperationInProgressException with lazy loading after update to 3.0.1

Hello, i have a DBContext which uses LazyLoading. After update to PostgreSQL 3.0.1 i get an exception iterating linked entities. I could reproduce the problem with a simple console example.

working with: Microsoft.EntityFrameworkCore 2.2.6 Microsoft.EntityFrameworkCore.Proxies 2.2.6 Npgsql.EntityFrameworkCore.PostgreSQL 2.2.4

not working with: Microsoft.EntityFrameworkCore 3.0.0 Microsoft.EntityFrameworkCore.Proxies 3.0.0 Npgsql.EntityFrameworkCore.PostgreSQL 3.0.1

Code to reproduce:

using Microsoft.EntityFrameworkCore;
using Microsoft.Extensions.Logging;
using System;
using System.Collections;
using System.Collections.Generic;
using System.Threading.Tasks;

namespace postgresProblem
{
	public class DemoContext : DbContext
	{
		public static readonly ILoggerFactory MyLoggerFactory
			= LoggerFactory.Create(builder => { builder.AddConsole(); });

		public DemoContext()
		{
		}

		public DbSet<DemoEntity_1> DemoEntities { get; set; }
		public DbSet<DemoEntity_2> SubEntities { get; set; }
		protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
		{
			optionsBuilder.UseLoggerFactory(MyLoggerFactory).UseLazyLoadingProxies().UseNpgsql("Host=10.1.99.84;Port=30432;Username=postgres;Password=demo;Database=test");
		}
	}

	public class DemoEntity_1
	{
		public DemoEntity_1()
		{
			SubEntities = new List<DemoEntity_2>();
		}

		public int Id { get; set; }
		public virtual ICollection<DemoEntity_2> SubEntities { get; set; }
	}

	public class DemoEntity_2
	{
		public DemoEntity_2()
		{

		}

		public int Id { get; set; }
		public string Name { get; set; }
		public virtual DemoEntity_1 DemoEntity { get; set; }
	}

	class Program
	{
		static async Task Main(string[] args)
		{
			using (DemoContext context = new DemoContext())
			{
				if (await context.Database.CanConnectAsync() == true)
				{
					foreach (var demoEntity in context.DemoEntities)
					{
						foreach (var subEntity in demoEntity.SubEntities)	//here the OperationInProgress-Exception occurs
						{
							await Console.Out.WriteLineAsync(subEntity.Name);
						}
					}
				}
				else
				{
					await context.Database.EnsureCreatedAsync();
					//create some demo stuff
					DemoEntity_2 subEntity1 = new DemoEntity_2 { Name = "subEntity1" };
					context.SubEntities.Add(subEntity1);
					DemoEntity_2 subEntity2 = new DemoEntity_2 { Name = "subEntity2" };
					context.SubEntities.Add(subEntity2);

					DemoEntity_1 demoEntity_1 = new DemoEntity_1();
					demoEntity_1.SubEntities.Add(subEntity1);
					demoEntity_1.SubEntities.Add(subEntity2);
					context.DemoEntities.Add(demoEntity_1);

					await context.SaveChangesAsync();
					await Console.Out.WriteLineAsync("demo stuff created");
				}
			}
		}
	}
}

Exception thrown:

‘Npgsql.NpgsqlOperationInProgressException’ in Microsoft.EntityFrameworkCore.Relational.dll An exception of type ‘Npgsql.NpgsqlOperationInProgressException’ occurred in Microsoft.EntityFrameworkCore.Relational.dll but was not handled in user code A command is already in progress: SELECT d.“Id” FROM “DemoEntities” AS d

StackTrace:

   at Npgsql.NpgsqlConnector.<StartUserAction>g__DoStartUserAction|187_0(<>c__DisplayClass187_0& )
   at Npgsql.NpgsqlConnector.StartUserAction(ConnectorState newState, NpgsqlCommand command)
   at Npgsql.NpgsqlCommand.<ExecuteReaderAsync>d__102.MoveNext()
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Threading.Tasks.ValueTask`1.get_Result()
   at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
   at Npgsql.NpgsqlCommand.ExecuteReader(CommandBehavior behavior)
   at Npgsql.NpgsqlCommand.ExecuteDbDataReader(CommandBehavior behavior)
   at System.Data.Common.DbCommand.ExecuteReader()
   at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReader(RelationalCommandParameterObject parameterObject)
   at Microsoft.EntityFrameworkCore.Query.RelationalShapedQueryCompilingExpressionVisitor.QueryingEnumerable`1.Enumerator.MoveNext()
   at Microsoft.EntityFrameworkCore.EntityFrameworkQueryableExtensions.Load[TSource](IQueryable`1 source)
   at Microsoft.EntityFrameworkCore.Internal.EntityFinder`1.Load(INavigation navigation, InternalEntityEntry entry)
   at Microsoft.EntityFrameworkCore.ChangeTracking.NavigationEntry.Load()
   at Microsoft.EntityFrameworkCore.ChangeTracking.CollectionEntry.Load()
   at Microsoft.EntityFrameworkCore.Internal.LazyLoader.Load(Object entity, String navigationName)
   at Microsoft.EntityFrameworkCore.Proxies.Internal.LazyLoadingInterceptor.Intercept(IInvocation invocation)
   at Castle.DynamicProxy.AbstractInvocation.Proceed()
   at Castle.Proxies.DemoEntity_1Proxy.get_SubEntities()
   at postgresProblem.Program.<Main>d__0.MoveNext() in C:\MyTemp\playground\postgresProblem\postgresProblem\Program.cs:line 60

Logger output

info: Microsoft.EntityFrameworkCore.Infrastructure[10403]
      Entity Framework Core 3.0.0 initialized 'DemoContext' using provider 'Npgsql.EntityFrameworkCore.PostgreSQL' with options: using lazy-loading proxies
info: Microsoft.EntityFrameworkCore.Database.Command[20100]
      Executing DbCommand [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT d."Id"
      FROM "DemoEntities" AS d
info: Microsoft.EntityFrameworkCore.Database.Command[20100]
      Executing DbCommand [Parameters=[@__p_0='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30']
      SELECT s."Id", s."DemoEntityId", s."Name"
      FROM "SubEntities" AS s
      WHERE ((s."DemoEntityId" = @__p_0) AND ((s."DemoEntityId" IS NOT NULL) AND (@__p_0 IS NOT NULL))) OR ((s."DemoEntityId" IS NULL) AND (@__p_0 IS NULL))
fail: Microsoft.EntityFrameworkCore.Database.Command[20102]
      Failed executing DbCommand (5ms) [Parameters=[@__p_0='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30']
      SELECT s."Id", s."DemoEntityId", s."Name"
      FROM "SubEntities" AS s
      WHERE ((s."DemoEntityId" = @__p_0) AND ((s."DemoEntityId" IS NOT NULL) AND (@__p_0 IS NOT NULL))) OR ((s."DemoEntityId" IS NULL) AND (@__p_0 IS NULL))
fail: Microsoft.EntityFrameworkCore.Query[10100]
      An exception occurred while iterating over the results of a query for context type 'postgresProblem.DemoContext'.
      Npgsql.NpgsqlOperationInProgressException: A command is already in progress: SELECT d."Id"
      FROM "DemoEntities" AS d
         at Npgsql.NpgsqlConnector.<StartUserAction>g__DoStartUserAction|187_0(<>c__DisplayClass187_0& )
         at Npgsql.NpgsqlConnector.StartUserAction(ConnectorState newState, NpgsqlCommand command)
         at Npgsql.NpgsqlCommand.ExecuteReaderAsync(CommandBehavior behavior, Boolean async, CancellationToken cancellationToken)
         at Npgsql.NpgsqlCommand.ExecuteReader(CommandBehavior behavior)
         at Npgsql.NpgsqlCommand.ExecuteDbDataReader(CommandBehavior behavior)
         at System.Data.Common.DbCommand.ExecuteReader()
         at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReader(RelationalCommandParameterObject parameterObject)
         at Microsoft.EntityFrameworkCore.Que
C:\MyTemp\playground\postgresProblem\postgresProblem\bin\Debug\netcoreapp3.0\postgresProblem.exe (process 22484) exited with code -1.

Is this a problem with the PostgreSQL package or with the EntityFrameworkCore package?

About this issue

  • Original URL
  • State: closed
  • Created 5 years ago
  • Reactions: 3
  • Comments: 16 (5 by maintainers)

Most upvoted comments

Sorry for not having answered this earlier - this is the expected behavior.

Where you enumerate over entities (without a ToArray or ToList), you are streaming them from the database - that means that the command to fetch them is still in progress, and EF Core reads one row at a time, materializes an entity instance and gives it back to you. Lazy loading means that another SQL query needs to get sent when you access the related entities (SubEntities in this case), but the connection is still busy with the results of the first query (DemoEntities). You’re effectively trying to execute two database commands on the same connection at the same time, a feature sometimes called Multiple Active Result Sets, which Npgsql/PostgreSQL does not support.

Workarounds include loading all the DemoEntities before starting to load the SubEntities (by placing a ToList/ToArray as suggested above), simply using eager loading (which loads everything in a single query), and possibly other patterns of loading related entities (see the docs).

using UseQuerySplittingBehavior(QuerySplittingBehavior.SplitQuery) also solves this issue.

.UseLazyLoadingProxies().UseNpgsql(connectionString, o => o.UseQuerySplittingBehavior(QuerySplittingBehavior.SplitQuery))