thepirat000 / Audit.NET

An extensible framework to audit executing operations in .NET and .NET Core.
MIT License
2.27k stars 323 forks source link

AuditCommandInterceptor IncludeReaderResults = true results in "DataReader Open" error #628

Closed thesammiller closed 11 months ago

thesammiller commented 1 year ago

Describe the bug Same as Issue 521

To Reproduce

Expected behavior Expect read events to be saved to the database without error. Update event should not cause an error with nested objects.

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

    <PackageReference Include="Audit.EntityFramework.Core" Version="21.0.3" />
    <PackageReference Include="Audit.NET" Version="21.0.3" />

Target .NET framework: For example:

    <TargetFramework>net7.0</TargetFramework>

Additional context There seems to be an issue with the ReaderExecuted workflow. Basically that method is executed for all commands, not just a READ operation. This is leading to creating additional DataReaders during a nested UPDATE and possibly losing track of one of the DataReaders.

We are able to resolve this issue with a patch to https://github.com/thepirat000/Audit.NET/blob/0485eb21e2947657536c14cff040659e4afcc15b/src/Audit.EntityFramework/Interceptors/AuditCommandInterceptor.cs#L302

To the conditional if (IncludeReaderResults && result != null && ) , add a check to make sure the query is a read (cmdEvent.CommandText.StartsWith("SELECT"). I'm not sure if this is the best way to resolve the issue, but things seem to be working for us.

thepirat000 commented 1 year ago

Just to clarify, What do you mean by "Update an object with nested children."?

Do you mean, something like this?

// for example in an Order->Items relation
var order = db.Orders.Where(o => o.Id == 1);
order.Status = "Modified";
order.OrderItems[0].Quantity += 1;
db.SaveChanges();
thesammiller commented 12 months ago

Yes, thank you. Updating an object that has children objects. Flat objects seem to work fine, but objects with relationships that have relationships trigger the issue.

{
   "Id": 1,
   "Status": "Modified",
   "Order Item" : {
         "Category": 1,
         "Details": {
             "Description": "Apple"
          }
     }
}
thepirat000 commented 12 months ago

Ok, finally I was able to reproduce.

The audit interceptor consumes the original SqlDataReader and, since it's forward-only, it will create and return a new DataTableReader with the same data as the result, so EF can consume the data.

But it seems that for some updates EF requires the results to be in the original SqlDataReader result untouched.

I can't find a way to detect if EF will require the original SqlDataReader to be untouched, so I still don't know how this can be fixed.

I will keep testing, but I guess the only way will be to disable the IncludeReaderResults.

Maybe allowing the user to define a predicate on the event data so that you can configure it like:

new AuditCommandInterceptor()
{
  IncludeReaderResultsIf = eventData => eventData.Command.CommandText.StartsWith("SELECT");
}
thesammiller commented 12 months ago

Thank you! I'm glad you were able to recreate it. Thank you for the description. The library has otherwise been working great. Really appreciate all your work!

thepirat000 commented 12 months ago

I've created this bug report for EF Core, hopefully, we get some answers from there:

https://github.com/dotnet/efcore/issues/31991

thepirat000 commented 12 months ago

I've identified the problem with the AuditCommandInterceptor.

When a command result contains multiple result sets, utilizing a DataTable to read the data will only process the initial result set, leaving the original data reader unclosed.

I'm working on the fix, but basically, it needs to use a DataSet instead of just a DataTable to consume the original reader and generate the new one.

thepirat000 commented 12 months ago

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

thesammiller commented 10 months ago

Belated update that things are working as expected for us. Thank you very much for your help!!

thepirat000 commented 10 months ago

Thank you !