There is already an open DataReader associated with this Connection which must be closed first

[chobo2]

Describe the bug While using AuditCommandInterceptor() { IncludeReaderResults = true } I will get an error saying a datareader needs to be closed first.

This does not seem to happy in all scenarios but only certain ones that I am still trying to pin down. So far it seems like when I tried to create multiple tables that are associated with each other and insert them in the the db.

fail: Microsoft.EntityFrameworkCore.Update[10000]

      An exception occurred in the database while saving changes for context type 'ApplicationDbContext'.

      System.InvalidOperationException: There is already an open DataReader associated with this Connection which must be closed first.

         at Microsoft.Data.SqlClient.SqlInternalConnectionTds.ValidateConnectionForExecute(SqlCommand command)

         at Microsoft.Data.SqlClient.SqlInternalTransaction.Rollback()

         at Microsoft.Data.SqlClient.SqlTransaction.Dispose(Boolean disposing)

         at Microsoft.EntityFrameworkCore.Storage.RelationalTransaction.Dispose()

         at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.Execute(IEnumerable`1 commandBatches, IRelationalConnection connection)

         at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(IList`1 entriesToSave)

         at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(StateManager stateManager, Boolean acceptAllChangesOnSuccess)

         at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](TState state, Func`3 operation, Func`3 verifySucceeded)

         at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(Boolean acceptAllChangesOnSuccess)

         at Microsoft.EntityFrameworkCore.DbContext.SaveChanges(Boolean acceptAllChangesOnSuccess)

      System.InvalidOperationException: There is already an open DataReader associated with this Connection which must be closed first.

         at Microsoft.Data.SqlClient.SqlInternalConnectionTds.ValidateConnectionForExecute(SqlCommand command)

         at Microsoft.Data.SqlClient.SqlInternalTransaction.Rollback()

         at Microsoft.Data.SqlClient.SqlTransaction.Dispose(Boolean disposing)

         at Microsoft.EntityFrameworkCore.Storage.RelationalTransaction.Dispose()

         at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.Execute(IEnumerable`1 commandBatches, IRelationalConnection connection)

         at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(IList`1 entriesToSave)

         at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(StateManager stateManager, Boolean acceptAllChangesOnSuccess)

         at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](TState state, Func`3 operation, Func`3 verifySucceeded)

         at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(Boolean acceptAllChangesOnSuccess)

         at Microsoft.EntityFrameworkCore.DbContext.SaveChanges(Boolean acceptAllChangesOnSuccess)

fail: CreateCommand[0]

      Request: Unhandled Exception for Request CreateCommand 

      System.InvalidOperationException: There is already an open DataReader associated with this Connection which must be closed first.

         at Microsoft.Data.SqlClient.SqlInternalConnectionTds.ValidateConnectionForExecute(SqlCommand command)

         at Microsoft.Data.SqlClient.SqlInternalTransaction.Rollback()

         at Microsoft.Data.SqlClient.SqlTransaction.Dispose(Boolean disposing)

         at Microsoft.EntityFrameworkCore.Storage.RelationalTransaction.Dispose()

         at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.Execute(IEnumerable`1 commandBatches, IRelationalConnection connection)

         at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(IList`1 entriesToSave)

         at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(StateManager stateManager, Boolean acceptAllChangesOnSuccess)

         at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](TState state, Func`3 operation, Func`3 verifySucceeded)

         at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(Boolean acceptAllChangesOnSuccess)

         at Microsoft.EntityFrameworkCore.DbContext.SaveChanges(Boolean acceptAllChangesOnSuccess)

         at Audit.EntityFramework.AuditDbContext.<>n__0(Boolean acceptAllChangesOnSuccess)

         at Audit.EntityFramework.AuditDbContext.<>c__DisplayClass51_0.<SaveChanges>b__0()

         at Audit.EntityFramework.DbContextHelper.SaveChanges(IAuditDbContext context, Func`1 baseSaveChanges)

         at Audit.EntityFramework.AuditDbContext.SaveChanges(Boolean acceptAllChangesOnSuccess)

         at dHandler.Handle(Command request, CancellationToken cancellationToken) in Command.cs:line 194

         at Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next) in ValidationBehaviour.cs:line 33

         at Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next) in AuthorizationBehaviour.cs:line 79

         at MediatR.Pipeline.RequestExceptionProcessorBehavior`2.Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next)

         at MediatR.Pipeline.RequestExceptionProcessorBehavior`2.Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next)

         at MediatR.Pipeline.RequestExceptionActionProcessorBehavior`2.Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next)

         at MediatR.Pipeline.RequestExceptionActionProcessorBehavior`2.Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next)

         at MediatR.Pipeline.RequestPostProcessorBehavior`2.Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next)

         at MediatR.Pipeline.RequestPreProcessorBehavior`2.Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next)

         at Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next) in UncaughtExceptionBehaviour.cs:line 27

fail: Grpc.AspNetCore.Server.ServerCallHandler[6]

      Error when executing service method 'Create'.

      System.InvalidOperationException: There is already an open DataReader associated with this Connection which must be closed first.

         at Microsoft.Data.SqlClient.SqlInternalConnectionTds.ValidateConnectionForExecute(SqlCommand command)

         at Microsoft.Data.SqlClient.SqlInternalTransaction.Rollback()

         at Microsoft.Data.SqlClient.SqlTransaction.Dispose(Boolean disposing)

         at Microsoft.EntityFrameworkCore.Storage.RelationalTransaction.Dispose()

         at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.Execute(IEnumerable`1 commandBatches, IRelationalConnection connection)

         at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(IList`1 entriesToSave)

         at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(StateManager stateManager, Boolean acceptAllChangesOnSuccess)

         at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](TState state, Func`3 operation, Func`3 verifySucceeded)

         at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(Boolean acceptAllChangesOnSuccess)

         at Microsoft.EntityFrameworkCore.DbContext.SaveChanges(Boolean acceptAllChangesOnSuccess)

         at Audit.EntityFramework.AuditDbContext.<>n__0(Boolean acceptAllChangesOnSuccess)

         at Audit.EntityFramework.AuditDbContext.<>c__DisplayClass51_0.<SaveChanges>b__0()

         at Audit.EntityFramework.DbContextHelper.SaveChanges(IAuditDbContext context, Func`1 baseSaveChanges)

         at Audit.EntityFramework.AuditDbContext.SaveChanges(Boolean acceptAllChangesOnSuccess)

         at Handle(Command request, CancellationToken cancellationToken) in Create.cs:line 194

         at ValidationBehaviour`2.Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next) in ValidationBehaviour.cs:line 33

         at AuthorizationBehaviour`2.Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next) in AuthorizationBehaviour.cs:line 79

         at MediatR.Pipeline.RequestExceptionProcessorBehavior`2.Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next)

         at MediatR.Pipeline.RequestExceptionProcessorBehavior`2.Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next)

         at MediatR.Pipeline.RequestExceptionActionProcessorBehavior`2.Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next)

         at MediatR.Pipeline.RequestExceptionActionProcessorBehavior`2.Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next)

         at MediatR.Pipeline.RequestPostProcessorBehavior`2.Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next)

         at MediatR.Pipeline.RequestPreProcessorBehavior`2.Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next)

         at Handle(TRequest request, CancellationToken cancellationToken, RequestHandlerDelegate`1 next) in UncaughtExceptionBehaviour.cs:line 27

         at Create(Request request, ServerCallContext context) in Service.cs:line 116

         at Grpc.Shared.Server.UnaryServerMethodInvoker`3.AwaitInvoker(Task`1 invokerTask, GrpcActivatorHandle`1 serviceHandle)

         at Grpc.Shared.Server.UnaryServerMethodInvoker`3.AwaitInvoker(Task`1 invokerTask, GrpcActivatorHandle`1 serviceHandle)

         at Grpc.AspNetCore.Server.Internal.CallHandlers.UnaryServerCallHandler`3.HandleCallAsyncCore(HttpContext httpContext, HttpContextServerCallContext serverCallContext)

         at Grpc.AspNetCore.Server.Internal.CallHandlers.ServerCallHandlerBase`3.<HandleCallAsync>g__AwaitHandleCall|8_0(HttpContextServerCallContext serverCallContext, Method`2 method, Task handleCall)

To Reproduce

I am not 100% sure, try creating something like this

context.TableA.Add(new TableA() {
   Name = "hi",
   TableBs = new List<TableB>() {
        new TableB() {
             Test = "test",
             TableC = new TableC() {
                 City = "City"
            }
        }
    }
}

Expected behavior It not to crash

Libraries (specify the Audit.NET extensions being used including version): For example:

• Audit.EntityFramework: currnet

Target .NET framework: For example:

• .NET 6

[thepirat000]

I was unable to reproduce this, please provide the operations you are doing before SaveChanges()

[chobo2]

I was unable to reproduce this, please provide the operations you are doing before SaveChanges()

Darn, hmm okay I will try to see if I can figure out some way to show how the code is as unfortunately I can't just copy and paste it here.

[thepirat000]

I understand.

I've tried with many different operations before the SaveChanges but it didn't thrown the exception.

[chobo2]

I understand.

I've tried with many different operations before the SaveChanges but it didn't thrown the exception.

I am still looking into it but it is so weird why it is happening.

The operations that are happening before is

1. where clause to find some records and if they exist delete all those records
2. A couple select statements using .Single and FindAsync
3. An insert statement that inserts into like 9 tables (1 parent table and 7 children tables)

the weird thing is really seems to be just coming from 1 of the children table but it is nothing really special.

code is like this

var TableC = new TableC() {
   name = "test",
  TableD = new TableD() {
    City = "City"
  }
}

var TableA = new TableA() {
    something = "test",
   TableDs = new LIst<TableD> { TableC }
}

context.TableA.Add(TableA);
context.SaveChangesAysnc(cancellation token) // also tried no aysnc

we do override the SaveChangeAysnc and update some values in the table automatically but again this does not seem to be the cause as I can leave that code as is and just comment out the TableD generation and everything will work

public class TableC : TableCBase {
    public virtual TableA TableA {get; set;}
   public int TableAId {get; set;}
}

public class TableCBase {
   public int Id {get; set;}
  public int TableDId {get; set;}
 pubic virtual TableD TableD {get; set;}

}

Any tips on how to debug this? Can I get into the library and follow it?

[thepirat000]

yes you can debug on your IDE, just download or clone the repo, and import/add the projects to your solution Audit.NET/Audit.NET.csproj & Audit.EntityFramework.Core/Audit.EntityFramework.Core.csproj

[chobo2]

yes you can debug on your IDE, just download or clone the repo, and import/add the projects to your solution Audit.NET/Audit.NET.csproj & Audit.EntityFramework.Core/Audit.EntityFramework.Core.csproj

Okay, I added AuditNet.csproj as an exiting project but it says there is some dependencies with .net45?

Also do I remove the nuget package versions while testing?

[thepirat000]

oh, I see, since it targets multiple .NET versions, I guess it will require you to have those SDK/runtimes installed.

And yes, you should remove the NuGet references temporarily and re-add the references as project references.

You can also try only importing Audit.EntityFramework.Core.csproj

[chobo2]

oh, I see, since it targets multiple .NET versions, I guess it will require you to have those SDK/runtimes installed.

And yes, you should remove the NuGet references temporarily and re-add the references as project references.

You can also try only importing Audit.EntityFramework.Core.csproj

Okay, I got it running was a bit tricky to find 4.5 but finally found it.

So I been following the code and I am seeing the problem in the AuditCommandInterceptors around line 119.

I am still not sure why it is failing the one thing I noticed in eventData was in the method that we are calling it has

• some select statements (5 of them)
• some insert statements ( 2 of them)

The code from ReadExecutedAsync method (line 112) will then run 7 times and each time eventData will have EF generated statements but each one seems to be in their own "transaction"

would look like this

SELECT TOP(1) [m].[Id], [m].[Enabled], [m].[Value]

FROM [SomePicklist] AS [m]

WHERE [m].[Id] = @__p_0

That could be the first run into that method then on the second run of the method it would look like this for an insert

SET NOCOUNT ON;

INSERT INTO [Address] ([City], [Country], [EndDate], [FKId], [Id], [State], [StreetAddress])

VALUES (@p34, @p35, @p36, @p37, @p38, @p39, @p40);

SELECT [Id]

FROM [Address]

WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity();

but then when it gets to the code that I suspect is causing trouble (can call this 3rd run into the the method.. though it is more like the last run into the method)

I see this

SET NOCOUNT ON;

INSERT INTO [Address] ([City], [Country], [EndDate], [FKId], [Id], [State], [StreetAddress])

VALUES (@p34, @p35, @p36, @p37, @p38, @p39, @p40);

SELECT [Id]

FROM [Address]

WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity();

INSERT INTO [Records] ([Id], [FKId], [Column1], [Created], [CreatedBy], [Details], [LastModified], [LastModifiedBy], [Column2], [Column3], [Column4], [Column5], [Column6])

VALUES (@p41, @p42, @p43, @p44, @p45, @p46, @p47, @p48, @p49, @p50, @p51, @p52, @p53);

INSERT INTO [TheBadTable] ([AddressId], [Created], [CreatedBy], [GivenName], [FKtId], [LastModified], [LastModifiedBy], [Phone], [Surname])

VALUES (@p54, @p55, @p56, @p57, @p58, @p59, @p60, @p61, @p62);

SELECT [Id]

FROM [TheBadTable]

WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity();

INSERT INTO [Table3] ([Id], [FkId], [Created], [CreatedBy], [Details], [LastModified], [LastModifiedBy], [History], [FkId2])

VALUES (@p63, @p64, @p65, @p66, @p67, @p68, @p69, @p70, @p71);

Suddenly it has grouped many statements together in the data, and 2 of them have select statements.

When I comment out the "TheBadTable" code so no longer inserts anything into that table, then all the statements are back to being separate and everything logs and saves with no issues.

This maybe not the issue but this what I noticed as a difference.

[thepirat000]

I'm still unable to reproduce.

It's very likely the problem is because the library replaces the original SqlDataReader by a cached DbDataReader, since they are forward-only and can be read only once. So probably in some cases, EF is expecting the original SqlDataReader.

This is how the interceptor works when IncludeReaderResults is true:

1. The interceptor reads the data from the original SqlDataReader from the context (Line 330)
2. Stores the data read into the audit event (Line 300)
3. Replaces the context DbDataReader with a fresh DbDataReader containing the original data (Line 85)

[chobo2]

I'm still unable to reproduce.

It's very likely the problem is because the library replaces the original SqlDataReader by a cached DbDataReader, since they are forward-only and can be read only once. So probably in some cases, EF is expecting the original SqlDataReader.

This is how the interceptor works when IncludeReaderResults is true:

1. The interceptor reads the data from the original SqlDataReader from the context (Line 330)
2. Stores the data read into the audit event (Line 300)
3. Replaces the context DbDataReader with a fresh DbDataReader containing the original data (Line 85)

Hmm, so how should we proceed, I am not sure what next to test or how to help resolve this problem.

[thepirat000]

Until I can reproduce it, I won't be able to help much. Could you try to create a minimal sample project that reproduces the exception?

Does the BadTable have any trigger on it?

[chobo2]

Until I can reproduce it, I won't be able to help much. Could you try to create a minimal sample project that reproduces the exception?

Does the BadTable have any trigger on it?

Okay, I will see what I can do, thought he project has many moving parts thinking it might be hard to recreate as well :(

No there are no triggers on it.

[thepirat000]

This was fixed in version 21.1.0, please upgrade your references and re-test