Destructuring EntityFramework's DbUpdateException causes DB Queries

[RehanSaeed]

See https://github.com/aspnet/EntityFrameworkCore/issues/15214 for details. Would be willing to accept a PR for this work.

[joelweiss]

I can submit a PR, but I don't know where to even start with writing tests for this.

void Main()
{
    string path = @"C:\\Temp\\TestUpdateExceptionLog.log";

    ILogger logger = new LoggerConfiguration()
        .Enrich.WithExceptionDetails(new DestructuringOptionsBuilder().WithDefaultDestructurers().WithDestructurers(new[] { new DbUpdateExceptionDestructurer() }))
        .WriteTo.Console()
        .WriteTo.RollingFile(new JsonFormatter(renderMessage: true), path)
        .CreateLogger();
    try
    {
        TestTestContext(logger);
        TestException();
    }
    catch (Exception ex)
    {
        logger.Error(ex, "Error");
    }
    Log.CloseAndFlush();
}

public class DbUpdateExceptionDestructurer : ExceptionDestructurer
{
    public override Type[] TargetTypes => new[] { typeof(DbUpdateException), typeof(DbUpdateConcurrencyException) };

    public override void Destructure(Exception exception, IExceptionPropertiesBag propertiesBag, Func<Exception, IReadOnlyDictionary<string, object>> destructureException)
    {
        base.Destructure(exception, propertiesBag, destructureException);

        var dbUpdateException = (DbUpdateException)exception;

        propertiesBag.AddProperty(nameof(DbUpdateException.Entries), dbUpdateException.Entries?.Select(e => new
        {
            EntryProperties = e.Properties.Select(p => new
            {
                PropertyName = p.Metadata.Name,
                p.OriginalValue,
                p.CurrentValue,
                p.IsTemporary,
                p.IsModified
            }),
            e.State
        }).ToList());
    }
}

public void TestTestContext(ILogger logger)
{
    var ctx = new TestContext();
    ctx.Database.EnsureDeleted();
    ctx.Database.EnsureCreated();
    logger.Information("Get first UserRole {@UserRole}", ctx.UserRoles.First());
}

const string _UserId = "0f7183fd-94f6-40de-9ee4-e30f4d3b6167";
const string _PhoneNumber = "5551234567";

public void TestException()
{
    var ctx = new TestContext();

    // First update pending
    var user = ctx.Users.First(u => u.UserId == _UserId);
    user.PhoneNumber = user.PhoneNumber == _PhoneNumber ? "2221234567" : "5551234567";

    // Second update pending
    var role = ctx.Roles.First();
    role.ConcurrencyStamp = Guid.NewGuid().ToString();

    // Foreign key issue
    for (int i = 0; i < 2; i++)
    {
        var userRole = new UserRole
        {
            UserId = _UserId,
            RoleId = Guid.NewGuid().ToString() // this role ID is not valid
        };

        ctx.Add(userRole);
    }

    ctx.SaveChanges();
}

public class User
{
    public User() => UserRoles = new List<UserRole>();
    public string UserId { get; set; }
    public string PhoneNumber { get; set; }
    public List<UserRole> UserRoles { get; set; }
}

public class Role
{
    public Role() => UserRoles = new List<UserRole>();
    public string RoleId { get; set; }
    public string ConcurrencyStamp { get; set; }
    public List<UserRole> UserRoles { get; set; }
}

public class UserRole
{
    public string UserRoleId { get; set; }
    public string UserId { get; set; }
    public string RoleId { get; set; }

    public User User { get; set; }
    public Role Role { get; set; }
}

public class TestContext : DbContext
{
    protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    {
        optionsBuilder.UseSqlServer(@"Server=localhost;Database=TestSerilogExceptions;Integrated Security=True");
    }

    protected override void OnModelCreating(ModelBuilder modelBuilder)
    {
        var users = new List<User>
        {
            new User
            {
                UserId = _UserId,
                PhoneNumber = _PhoneNumber
            }
        };
        for (int i = 0; i < 10; i++)
        {
            users.Add(new User
            {
                UserId = Guid.NewGuid().ToString(),
                PhoneNumber = i.ToString()
            });
        }
        var role = new Role
        {
            RoleId = Guid.NewGuid().ToString()
        };
        var userRole = new UserRole
        {
            UserRoleId = Guid.NewGuid().ToString(),
            UserId = users[0].UserId,
            RoleId = role.RoleId
        };

        modelBuilder.Entity<User>().HasData(users);
        modelBuilder.Entity<Role>().HasData(role);
        modelBuilder.Entity<UserRole>().HasData(userRole);
    }

    public DbSet<User> Users { get; set; }
    public DbSet<Role> Roles { get; set; }
    public DbSet<UserRole> UserRoles { get; set; }

}

Here is the log output with DbUpdateExceptionDestructurer

{
   "Timestamp":"2019-06-27T18:41:12.5015751-04:00",
   "Level":"Error",
   "MessageTemplate":"Error",
   "RenderedMessage":"Error",
   "Exception":"Microsoft.EntityFrameworkCore.DbUpdateException: An error occurred while updating the entries. See the inner exception for details. ---> System.Data.SqlClient.SqlException: The INSERT statement conflicted with the FOREIGN KEY constraint \"FK_UserRoles_Roles_RoleId\". The conflict occurred in database \"TestSerilogExceptions\", table \"dbo.Roles\", column 'RoleId'.\r\n   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)\r\n   at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)\r\n   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)\r\n   at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)\r\n   at System.Data.SqlClient.SqlDataReader.TryHasMoreRows(Boolean& moreRows)\r\n   at System.Data.SqlClient.SqlDataReader.TryHasMoreResults(Boolean& moreResults)\r\n   at System.Data.SqlClient.SqlDataReader.TryNextResult(Boolean& more)\r\n   at System.Data.SqlClient.SqlDataReader.NextResult()\r\n   at Microsoft.EntityFrameworkCore.Update.AffectedCountModificationCommandBatch.Consume(RelationalDataReader reader)\r\n   --- End of inner exception stack trace ---\r\n   at Microsoft.EntityFrameworkCore.Update.AffectedCountModificationCommandBatch.Consume(RelationalDataReader reader)\r\n   at Microsoft.EntityFrameworkCore.Update.ReaderModificationCommandBatch.Execute(IRelationalConnection connection)\r\n   at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.Execute(DbContext _, ValueTuple`2 parameters)\r\n   at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](TState state, Func`3 operation, Func`3 verifySucceeded)\r\n   at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.Execute(IEnumerable`1 commandBatches, IRelationalConnection connection)\r\n   at Microsoft.EntityFrameworkCore.Storage.RelationalDatabase.SaveChanges(IReadOnlyList`1 entries)\r\n   at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(IReadOnlyList`1 entriesToSave)\r\n   at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(Boolean acceptAllChangesOnSuccess)\r\n   at Microsoft.EntityFrameworkCore.DbContext.SaveChanges(Boolean acceptAllChangesOnSuccess)\r\n   at Microsoft.EntityFrameworkCore.DbContext.SaveChanges()\r\n   at UserQuery.TestException() in C:\\Users\\yoel\\AppData\\Local\\Temp\\LINQPad5\\_jiudzuoy\\xdanpy\\LINQPadQuery.cs:line 118\r\n   at UserQuery.Main() in C:\\Users\\yoel\\AppData\\Local\\Temp\\LINQPad5\\_jiudzuoy\\xdanpy\\LINQPadQuery.cs:line 49",
   "Properties":{
      "ExceptionDetail":{
         "Type":"Microsoft.EntityFrameworkCore.DbUpdateException",
         "HResult":-2146233088,
         "Message":"An error occurred while updating the entries. See the inner exception for details.",
         "Source":"Microsoft.EntityFrameworkCore.Relational",
         "StackTrace":"   at Microsoft.EntityFrameworkCore.Update.AffectedCountModificationCommandBatch.Consume(RelationalDataReader reader)\r\n   at Microsoft.EntityFrameworkCore.Update.ReaderModificationCommandBatch.Execute(IRelationalConnection connection)\r\n   at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.Execute(DbContext _, ValueTuple`2 parameters)\r\n   at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](TState state, Func`3 operation, Func`3 verifySucceeded)\r\n   at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.Execute(IEnumerable`1 commandBatches, IRelationalConnection connection)\r\n   at Microsoft.EntityFrameworkCore.Storage.RelationalDatabase.SaveChanges(IReadOnlyList`1 entries)\r\n   at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(IReadOnlyList`1 entriesToSave)\r\n   at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(Boolean acceptAllChangesOnSuccess)\r\n   at Microsoft.EntityFrameworkCore.DbContext.SaveChanges(Boolean acceptAllChangesOnSuccess)\r\n   at Microsoft.EntityFrameworkCore.DbContext.SaveChanges()\r\n   at UserQuery.TestException() in C:\\Users\\yoel\\AppData\\Local\\Temp\\LINQPad5\\_jiudzuoy\\xdanpy\\LINQPadQuery.cs:line 118\r\n   at UserQuery.Main() in C:\\Users\\yoel\\AppData\\Local\\Temp\\LINQPad5\\_jiudzuoy\\xdanpy\\LINQPadQuery.cs:line 49",
         "TargetSite":"Void Consume(Microsoft.EntityFrameworkCore.Storage.RelationalDataReader)",
         "InnerException":{
            "Data":{
               "HelpLink.ProdName":"Microsoft SQL Server",
               "HelpLink.ProdVer":"13.00.4224",
               "HelpLink.EvtSrc":"MSSQLServer",
               "HelpLink.EvtID":"547",
               "HelpLink.BaseHelpUrl":"http://go.microsoft.com/fwlink",
               "HelpLink.LinkId":"20476"
            },
            "HResult":-2146232060,
            "Message":"The INSERT statement conflicted with the FOREIGN KEY constraint \"FK_UserRoles_Roles_RoleId\". The conflict occurred in database \"TestSerilogExceptions\", table \"dbo.Roles\", column 'RoleId'.",
            "Source":".Net SqlClient Data Provider",
            "StackTrace":"   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)\r\n   at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)\r\n   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)\r\n   at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)\r\n   at System.Data.SqlClient.SqlDataReader.TryHasMoreRows(Boolean& moreRows)\r\n   at System.Data.SqlClient.SqlDataReader.TryHasMoreResults(Boolean& moreResults)\r\n   at System.Data.SqlClient.SqlDataReader.TryNextResult(Boolean& more)\r\n   at System.Data.SqlClient.SqlDataReader.NextResult()\r\n   at Microsoft.EntityFrameworkCore.Update.AffectedCountModificationCommandBatch.Consume(RelationalDataReader reader)",
            "TargetSite":"Void OnError(System.Data.SqlClient.SqlException, Boolean, System.Action`1[System.Action])",
            "Errors":[
               {
                  "Source":".Net SqlClient Data Provider",
                  "Number":547,
                  "State":0,
                  "Class":16,
                  "Server":"localhost",
                  "Message":"The INSERT statement conflicted with the FOREIGN KEY constraint \"FK_UserRoles_Roles_RoleId\". The conflict occurred in database \"TestSerilogExceptions\", table \"dbo.Roles\", column 'RoleId'.",
                  "Procedure":"",
                  "LineNumber":6
               }
            ],
            "ClientConnectionId":"81d7b4ce-98c1-45da-9ce6-d398785364cd",
            "Class":16,
            "LineNumber":6,
            "Number":547,
            "Procedure":"",
            "Server":"localhost",
            "State":0,
            "ErrorCode":-2146232060,
            "Type":"System.Data.SqlClient.SqlException"
         },
         "Entries":[
            {
               "EntryProperties":[
                  {
                     "PropertyName":"UserRoleId",
                     "OriginalValue":"359047e3-34c4-4dfd-9edf-a8143683cb85",
                     "CurrentValue":"359047e3-34c4-4dfd-9edf-a8143683cb85",
                     "IsTemporary":false,
                     "IsModified":false
                  },
                  {
                     "PropertyName":"RoleId",
                     "OriginalValue":"6bd8dce0-c9a3-47df-baac-4854ef9d2e0d",
                     "CurrentValue":"6bd8dce0-c9a3-47df-baac-4854ef9d2e0d",
                     "IsTemporary":false,
                     "IsModified":false
                  },
                  {
                     "PropertyName":"UserId",
                     "OriginalValue":"0f7183fd-94f6-40de-9ee4-e30f4d3b6167",
                     "CurrentValue":"0f7183fd-94f6-40de-9ee4-e30f4d3b6167",
                     "IsTemporary":false,
                     "IsModified":false
                  }
               ],
               "State":"Added"
            }
         ]
      }
   }
}

And here is the log output without DbUpdateExceptionDestructurer, as you can see it has all the users from the database

{
   "Timestamp":"2019-06-27T18:11:48.3213016-04:00",
   "Level":"Error",
   "MessageTemplate":"Error",
   "RenderedMessage":"Error",
   "Exception":"Microsoft.EntityFrameworkCore.DbUpdateException: An error occurred while updating the entries. See the inner exception for details. ---> System.Data.SqlClient.SqlException: The INSERT statement conflicted with the FOREIGN KEY constraint \"FK_UserRoles_Roles_RoleId\". The conflict occurred in database \"TestSerilogExceptions\", table \"dbo.Roles\", column 'RoleId'.\r\n   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)\r\n   at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)\r\n   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)\r\n   at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)\r\n   at System.Data.SqlClient.SqlDataReader.TryHasMoreRows(Boolean& moreRows)\r\n   at System.Data.SqlClient.SqlDataReader.TryHasMoreResults(Boolean& moreResults)\r\n   at System.Data.SqlClient.SqlDataReader.TryNextResult(Boolean& more)\r\n   at System.Data.SqlClient.SqlDataReader.NextResult()\r\n   at Microsoft.EntityFrameworkCore.Update.AffectedCountModificationCommandBatch.Consume(RelationalDataReader reader)\r\n   --- End of inner exception stack trace ---\r\n   at Microsoft.EntityFrameworkCore.Update.AffectedCountModificationCommandBatch.Consume(RelationalDataReader reader)\r\n   at Microsoft.EntityFrameworkCore.Update.ReaderModificationCommandBatch.Execute(IRelationalConnection connection)\r\n   at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.Execute(DbContext _, ValueTuple`2 parameters)\r\n   at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](TState state, Func`3 operation, Func`3 verifySucceeded)\r\n   at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.Execute(IEnumerable`1 commandBatches, IRelationalConnection connection)\r\n   at Microsoft.EntityFrameworkCore.Storage.RelationalDatabase.SaveChanges(IReadOnlyList`1 entries)\r\n   at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(IReadOnlyList`1 entriesToSave)\r\n   at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(Boolean acceptAllChangesOnSuccess)\r\n   at Microsoft.EntityFrameworkCore.DbContext.SaveChanges(Boolean acceptAllChangesOnSuccess)\r\n   at Microsoft.EntityFrameworkCore.DbContext.SaveChanges()\r\n   at UserQuery.TestException() in C:\\Users\\yoel\\AppData\\Local\\Temp\\LINQPad5\\_jiudzuoy\\gyaurl\\LINQPadQuery.cs:line 118\r\n   at UserQuery.Main() in C:\\Users\\yoel\\AppData\\Local\\Temp\\LINQPad5\\_jiudzuoy\\gyaurl\\LINQPadQuery.cs:line 49",
   "Properties":{
      "ExceptionDetail":{
         "HResult":-2146233088,
         "Message":"An error occurred while updating the entries. See the inner exception for details.",
         "Source":"Microsoft.EntityFrameworkCore.Relational",
         "StackTrace":"   at Microsoft.EntityFrameworkCore.Update.AffectedCountModificationCommandBatch.Consume(RelationalDataReader reader)\r\n   at Microsoft.EntityFrameworkCore.Update.ReaderModificationCommandBatch.Execute(IRelationalConnection connection)\r\n   at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.Execute(DbContext _, ValueTuple`2 parameters)\r\n   at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](TState state, Func`3 operation, Func`3 verifySucceeded)\r\n   at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.Execute(IEnumerable`1 commandBatches, IRelationalConnection connection)\r\n   at Microsoft.EntityFrameworkCore.Storage.RelationalDatabase.SaveChanges(IReadOnlyList`1 entries)\r\n   at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(IReadOnlyList`1 entriesToSave)\r\n   at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChanges(Boolean acceptAllChangesOnSuccess)\r\n   at Microsoft.EntityFrameworkCore.DbContext.SaveChanges(Boolean acceptAllChangesOnSuccess)\r\n   at Microsoft.EntityFrameworkCore.DbContext.SaveChanges()\r\n   at UserQuery.TestException() in C:\\Users\\yoel\\AppData\\Local\\Temp\\LINQPad5\\_jiudzuoy\\gyaurl\\LINQPadQuery.cs:line 118\r\n   at UserQuery.Main() in C:\\Users\\yoel\\AppData\\Local\\Temp\\LINQPad5\\_jiudzuoy\\gyaurl\\LINQPadQuery.cs:line 49",
         "TargetSite":"Void Consume(Microsoft.EntityFrameworkCore.Storage.RelationalDataReader)",
         "InnerException":{
            "Data":{
               "HelpLink.ProdName":"Microsoft SQL Server",
               "HelpLink.ProdVer":"13.00.4224",
               "HelpLink.EvtSrc":"MSSQLServer",
               "HelpLink.EvtID":"547",
               "HelpLink.BaseHelpUrl":"http://go.microsoft.com/fwlink",
               "HelpLink.LinkId":"20476"
            },
            "HResult":-2146232060,
            "Message":"The INSERT statement conflicted with the FOREIGN KEY constraint \"FK_UserRoles_Roles_RoleId\". The conflict occurred in database \"TestSerilogExceptions\", table \"dbo.Roles\", column 'RoleId'.",
            "Source":".Net SqlClient Data Provider",
            "StackTrace":"   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)\r\n   at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)\r\n   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)\r\n   at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)\r\n   at System.Data.SqlClient.SqlDataReader.TryHasMoreRows(Boolean& moreRows)\r\n   at System.Data.SqlClient.SqlDataReader.TryHasMoreResults(Boolean& moreResults)\r\n   at System.Data.SqlClient.SqlDataReader.TryNextResult(Boolean& more)\r\n   at System.Data.SqlClient.SqlDataReader.NextResult()\r\n   at Microsoft.EntityFrameworkCore.Update.AffectedCountModificationCommandBatch.Consume(RelationalDataReader reader)",
            "TargetSite":"Void OnError(System.Data.SqlClient.SqlException, Boolean, System.Action`1[System.Action])",
            "Errors":[
               {
                  "Source":".Net SqlClient Data Provider",
                  "Number":547,
                  "State":0,
                  "Class":16,
                  "Server":"localhost",
                  "Message":"The INSERT statement conflicted with the FOREIGN KEY constraint \"FK_UserRoles_Roles_RoleId\". The conflict occurred in database \"TestSerilogExceptions\", table \"dbo.Roles\", column 'RoleId'.",
                  "Procedure":"",
                  "LineNumber":6
               }
            ],
            "ClientConnectionId":"e1bedbe9-523b-4472-9d6b-c13f6a7ee960",
            "Class":16,
            "LineNumber":6,
            "Number":547,
            "Procedure":"",
            "Server":"localhost",
            "State":0,
            "ErrorCode":-2146232060,
            "Type":"System.Data.SqlClient.SqlException"
         },
         "Entries":[
            {
               "Entity":{
                  "UserRoleId":"2c1fd503-233e-48e4-adf3-275be0db6954",
                  "UserId":"0f7183fd-94f6-40de-9ee4-e30f4d3b6167",
                  "RoleId":"d0f67c78-13cd-40f4-aff8-388751f19344",
                  "$id":"1",
                  "User":{
                     "UserId":"0f7183fd-94f6-40de-9ee4-e30f4d3b6167",
                     "PhoneNumber":"2221234567",
                     "$id":"2",
                     "UserRoles":[
                        {
                           "$ref":"1"
                        },
                        {
                           "UserRoleId":"19363261-629b-4662-9623-0e23f77a4067",
                           "UserId":"0f7183fd-94f6-40de-9ee4-e30f4d3b6167",
                           "RoleId":"6c903de7-3639-4a17-b8a0-54521794c409",
                           "User":{
                              "$ref":"2"
                           },
                           "Role":null
                        }
                     ]
                  },
                  "Role":null
               },
               "State":"Added",
               "Context":{
                  "Users":[
                     {
                        "$ref":"2"
                     },
                     {
                        "UserId":"1202a1ad-e962-440d-9b0a-624d225a1ce8",
                        "PhoneNumber":"8",
                        "UserRoles":[

                        ]
                     },
                     {
                        "UserId":"1453e4ea-331f-489a-bd3d-1035a45c0c94",
                        "PhoneNumber":"5",
                        "UserRoles":[

                        ]
                     },
                     {
                        "UserId":"2f6d8803-9603-4c61-94a3-9e14da14cb16",
                        "PhoneNumber":"7",
                        "UserRoles":[

                        ]
                     },
                     {
                        "UserId":"45894ee8-b604-452b-821c-a2fef4f883b3",
                        "PhoneNumber":"9",
                        "UserRoles":[

                        ]
                     },
                     {
                        "UserId":"4e43eb9f-4d6f-460a-bb2d-bfae4ffb17a4",
                        "PhoneNumber":"3",
                        "UserRoles":[

                        ]
                     },
                     {
                        "UserId":"63814037-044c-417e-aeea-c4873f412fe5",
                        "PhoneNumber":"2",
                        "UserRoles":[

                        ]
                     },
                     {
                        "UserId":"93cd1260-2bef-4c90-a74a-cc6cdee31808",
                        "PhoneNumber":"0",
                        "UserRoles":[

                        ]
                     },
                     {
                        "UserId":"a54e7028-99d8-441f-8816-e816eff56f44",
                        "PhoneNumber":"4",
                        "UserRoles":[

                        ]
                     },
                     {
                        "UserId":"d25a2313-5e2a-40c4-9655-db27a0813632",
                        "PhoneNumber":"1",
                        "UserRoles":[

                        ]
                     },
                     {
                        "UserId":"e0d37b27-ed3b-4fe0-9e89-a10495fb8705",
                        "PhoneNumber":"6",
                        "UserRoles":[

                        ]
                     }
                  ],
                  "Roles":[
                     {
                        "RoleId":"9a2528b5-c83b-4a2a-a402-941eb43c8589",
                        "ConcurrencyStamp":"264fc469-c8cd-4650-bb9b-94f4df17d1ab",
                        "UserRoles":[

                        ],
                        "$id":"3"
                     }
                  ],
                  "UserRoles":[
                     {
                        "UserRoleId":"84df7a58-2025-430b-9f74-fb8de2a32d90",
                        "UserId":"0f7183fd-94f6-40de-9ee4-e30f4d3b6167",
                        "RoleId":"9a2528b5-c83b-4a2a-a402-941eb43c8589",
                        "User":{
                           "$ref":"2"
                        },
                        "Role":{
                           "$ref":"3"
                        }
                     }
                  ],
                  "Database":{
                     "CurrentTransaction":null,
                     "AutoTransactionsEnabled":true,
                     "ProviderName":"Microsoft.EntityFrameworkCore.SqlServer"
                  },
                  "$id":"4",
                  "ChangeTracker":{
                     "AutoDetectChangesEnabled":true,
                     "LazyLoadingEnabled":true,
                     "QueryTrackingBehavior":"TrackAll",
                     "Context":{
                        "$ref":"4"
                     }
                  },
                  "Model":{
                     "ChangeTrackingStrategy":"Snapshot",
                     "ConventionDispatcher":{
                        "Tracker":{

                        }
                     },
                     "$id":"6",
                     "Builder":"threw System.ArgumentException: An item with the same key has already been added.",
                     "DebugView":{
                        "View":"Model: \r\n  EntityType: Role\r\n    Properties: \r\n      RoleId (string) Required PK AfterSave:Throw ValueGenerated.OnAdd 0 0 0 -1 0\r\n        Annotations: \r\n          Relational:TypeMapping: Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerStringTypeMapping\r\n      ConcurrencyStamp (string) 1 1 -1 -1 -1\r\n        Annotations: \r\n          Relational:TypeMapping: Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerStringTypeMapping\r\n    Navigations: \r\n      UserRoles (<UserRoles>k__BackingField, List<UserRole>) Collection ToDependent UserRole Inverse: Role 0 -1 1 -1 -1\r\n    Keys: \r\n      RoleId PK\r\n    Annotations: \r\n      ConstructorBinding: Microsoft.EntityFrameworkCore.Metadata.Internal.DirectConstructorBinding\r\n      Relational:TableName: Roles\r\n  EntityType: User\r\n    Properties: \r\n      UserId (string) Required PK AfterSave:Throw ValueGenerated.OnAdd 0 0 0 -1 0\r\n        Annotations: \r\n          Relational:TypeMapping: Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerStringTypeMapping\r\n      PhoneNumber (string) 1 1 -1 -1 -1\r\n        Annotations: \r\n          Relational:TypeMapping: Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerStringTypeMapping\r\n    Navigations: \r\n      UserRoles (<UserRoles>k__BackingField, List<UserRole>) Collection ToDependent UserRole Inverse: User 0 -1 1 -1 -1\r\n    Keys: \r\n      UserId PK\r\n    Annotations: \r\n      ConstructorBinding: Microsoft.EntityFrameworkCore.Metadata.Internal.DirectConstructorBinding\r\n      Relational:TableName: Users\r\n  EntityType: UserRole\r\n    Properties: \r\n      UserRoleId (string) Required PK AfterSave:Throw ValueGenerated.OnAdd 0 0 0 -1 0\r\n        Annotations: \r\n          Relational:TypeMapping: Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerStringTypeMapping\r\n      RoleId (string) FK Index 1 1 1 -1 1\r\n        Annotations: \r\n          Relational:TypeMapping: Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerStringTypeMapping\r\n      UserId (string) FK Index 2 2 2 -1 2\r\n        Annotations: \r\n          Relational:TypeMapping: Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerStringTypeMapping\r\n    Navigations: \r\n      Role (<Role>k__BackingField, Role) ToPrincipal Role Inverse: UserRoles 0 -1 3 -1 -1\r\n      User (<User>k__BackingField, User) ToPrincipal User Inverse: UserRoles 1 -1 4 -1 -1\r\n    Keys: \r\n      UserRoleId PK\r\n    Foreign keys: \r\n      UserRole {'RoleId'} -> Role {'RoleId'} ToDependent: UserRoles ToPrincipal: Role\r\n      UserRole {'UserId'} -> User {'UserId'} ToDependent: UserRoles ToPrincipal: User\r\n    Annotations: \r\n      ConstructorBinding: Microsoft.EntityFrameworkCore.Metadata.Internal.DirectConstructorBinding\r\n      Relational:TableName: UserRoles\r\nAnnotations: \r\n  ProductVersion: 2.2.4-servicing-10062\r\n  Relational:MaxIdentifierLength: 128\r\n  SqlServer:ValueGenerationStrategy: IdentityColumn"
                     }
                  }
               },
               "Metadata":{
                  "$id":"7",
                  "Builder":"threw System.ArgumentException: An item with the same key has already been added.",
                  "BaseType":null,
                  "QueryFilter":null,
                  "DefiningQuery":null,
                  "IsQueryType":false,
                  "DefiningNavigationName":null,
                  "DefiningEntityType":null,
                  "ChangeTrackingStrategy":"Snapshot",
                  "Counts":{
                     "PropertyCount":3,
                     "NavigationCount":2,
                     "OriginalValueCount":3,
                     "ShadowCount":0,
                     "RelationshipCount":5,
                     "StoreGeneratedCount":3
                  },
                  "RelationshipSnapshotFactory":{
                     "Method":"Microsoft.EntityFrameworkCore.ChangeTracking.Internal.ISnapshot lambda_method(System.Runtime.CompilerServices.Closure, Microsoft.EntityFrameworkCore.ChangeTracking.Internal.InternalEntityEntry)",
                     "Target":{

                     }
                  },
                  "OriginalValuesFactory":{
                     "Method":"Microsoft.EntityFrameworkCore.ChangeTracking.Internal.ISnapshot lambda_method(System.Runtime.CompilerServices.Closure, Microsoft.EntityFrameworkCore.ChangeTracking.Internal.InternalEntityEntry)",
                     "Target":{

                     }
                  },
                  "ShadowValuesFactory":{
                     "Method":"Microsoft.EntityFrameworkCore.ChangeTracking.Internal.ISnapshot <Create>b__0_0(Microsoft.EntityFrameworkCore.Storage.ValueBuffer)",
                     "Target":{

                     },
                     "$id":"17"
                  },
                  "EmptyShadowValuesFactory":{
                     "Method":"Microsoft.EntityFrameworkCore.ChangeTracking.Internal.ISnapshot <CreateEmpty>b__0_0()",
                     "Target":{

                     },
                     "$id":"18"
                  },
                  "DebugView":{
                     "View":"EntityType: UserRole\r\n  Properties: \r\n    UserRoleId (string) Required PK AfterSave:Throw ValueGenerated.OnAdd 0 0 0 -1 0\r\n      Annotations: \r\n        Relational:TypeMapping: Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerStringTypeMapping\r\n    RoleId (string) FK Index 1 1 1 -1 1\r\n      Annotations: \r\n        Relational:TypeMapping: Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerStringTypeMapping\r\n    UserId (string) FK Index 2 2 2 -1 2\r\n      Annotations: \r\n        Relational:TypeMapping: Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerStringTypeMapping\r\n  Navigations: \r\n    Role (<Role>k__BackingField, Role) ToPrincipal Role Inverse: UserRoles 0 -1 3 -1 -1\r\n    User (<User>k__BackingField, User) ToPrincipal User Inverse: UserRoles 1 -1 4 -1 -1\r\n  Keys: \r\n    UserRoleId PK\r\n  Foreign keys: \r\n    UserRole {'RoleId'} -> Role {'RoleId'} ToDependent: UserRoles ToPrincipal: Role\r\n    UserRole {'UserId'} -> User {'UserId'} ToDependent: UserRoles ToPrincipal: User\r\n  Annotations: \r\n    ConstructorBinding: Microsoft.EntityFrameworkCore.Metadata.Internal.DirectConstructorBinding\r\n    Relational:TableName: UserRoles"
                  },
                  "ClrType":"UserQuery+UserRole",
                  "Model":{
                     "$ref":"6"
                  },
                  "Name":"UserQuery+UserRole"
               },
               "Members":"threw System.ArgumentException: An item with the same key has already been added.",
               "Navigations":"threw System.ArgumentException: An item with the same key has already been added.",
               "Properties":"threw System.ArgumentException: An item with the same key has already been added.",
               "References":"threw System.ArgumentException: An item with the same key has already been added.",
               "Collections":[

               ],
               "IsKeySet":true,
               "CurrentValues":{
                  "Properties":[
                     {
                        "$ref":"8"
                     },
                     {
                        "$ref":"10"
                     },
                     {
                        "DeclaringEntityType":{
                           "$ref":"7"
                        },
                        "DeclaringType":{
                           "$ref":"7"
                        },
                        "ClrType":"System.String",
                        "$id":"16",
                        "Builder":"threw System.ArgumentException: An item with the same key has already been added.",
                        "IsNullable":true,
                        "ValueGenerated":"Never",
                        "BeforeSaveBehavior":"Save",
                        "AfterSaveBehavior":"Save",
                        "IsReadOnlyBeforeSave":false,
                        "IsReadOnlyAfterSave":false,
                        "IsConcurrencyToken":false,
                        "IsStoreGeneratedAlways":false,
                        "PrimaryKey":null,
                        "Keys":null,
                        "ForeignKeys":[
                           {
                              "Properties":[
                                 {

                                 }
                              ],
                              "$id":"20",
                              "PrincipalKey":{
                                 "Properties":[
                                    null
                                 ],
                                 "DeclaringEntityType":{

                                 },
                                 "$id":"19",
                                 "Builder":"threw System.ArgumentException: An item with the same key has already been added.",
                                 "IdentityMapFactory":{

                                 },
                                 "WeakReferenceIdentityMapFactory":{

                                 },
                                 "ReferencingForeignKeys":[
                                    null
                                 ],
                                 "DebugView":{

                                 }
                              },
                              "DeclaringEntityType":{
                                 "$ref":"7"
                              },
                              "PrincipalEntityType":{
                                 "$ref":"21"
                              },
                              "Builder":"threw System.ArgumentException: An item with the same key has already been added.",
                              "DependentToPrincipal":{
                                 "ClrType":"UserQuery+User",
                                 "ForeignKey":{

                                 },
                                 "$id":"22",
                                 "Builder":"threw System.ArgumentException: An item with the same key has already been added.",
                                 "IsEagerLoaded":false,
                                 "DeclaringEntityType":{

                                 },
                                 "DeclaringType":{

                                 },
                                 "CollectionAccessor":null,
                                 "DebugView":{

                                 },
                                 "Name":"User",
                                 "IsShadowProperty":false,
                                 "PropertyInfo":"User User",
                                 "FieldInfo":"User <User>k__BackingField",
                                 "PropertyIndexes":{

                                 },
                                 "Getter":{

                                 },
                                 "Setter":{

                                 },
                                 "Accessors":{

                                 }
                              },
                              "PrincipalToDependent":{
                                 "ClrType":"System.Collections.Generic.List`1[UserQuery+UserRole]",
                                 "ForeignKey":{

                                 },
                                 "$id":"23",
                                 "Builder":"threw System.ArgumentException: An item with the same key has already been added.",
                                 "IsEagerLoaded":false,
                                 "DeclaringEntityType":{

                                 },
                                 "DeclaringType":{

                                 },
                                 "CollectionAccessor":{

                                 },
                                 "DebugView":{

                                 },
                                 "Name":"UserRoles",
                                 "IsShadowProperty":false,
                                 "PropertyInfo":"System.Collections.Generic.List`1[UserQuery+UserRole] UserRoles",
                                 "FieldInfo":"System.Collections.Generic.List`1[UserQuery+UserRole] <UserRoles>k__BackingField",
                                 "PropertyIndexes":{

                                 },
                                 "Getter":{

                                 },
                                 "Setter":{

                                 },
                                 "Accessors":{

                                 }
                              },
                              "IsUnique":false,
                              "IsRequired":false,
                              "DeleteBehavior":"ClientSetNull",
                              "IsOwnership":false,
                              "DependentKeyValueFactory":{

                              },
                              "DependentsMapFactory":{
                                 "Method":"Microsoft.EntityFrameworkCore.ChangeTracking.Internal.IDependentsMap <CreateSimpleFactory>b__0()",
                                 "Target":{

                                 }
                              },
                              "DebugView":{
                                 "View":"UserRole {'UserId'} -> User {'UserId'} ToDependent: UserRoles ToPrincipal: User"
                              }
                           }
                        ],
                        "Indexes":[
                           {
                              "Properties":{
                                 "$ref":"Cyclic reference"
                              },
                              "DeclaringEntityType":{
                                 "$ref":"7"
                              },
                              "$id":"24",
                              "Builder":"threw System.ArgumentException: An item with the same key has already been added.",
                              "IsUnique":false,
                              "DebugView":{
                                 "View":"UserId"
                              }
                           }
                        ],
                        "DebugView":{
                           "View":"UserId (string) FK Index 2 2 2 -1 2\r\n  Annotations: \r\n    Relational:TypeMapping: Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerStringTypeMapping"
                        },
                        "Name":"UserId",
                        "IsShadowProperty":false,
                        "PropertyInfo":"System.String UserId",
                        "FieldInfo":"System.String <UserId>k__BackingField",
                        "PropertyIndexes":{
                           "Index":2,
                           "OriginalValueIndex":2,
                           "ShadowIndex":-1,
                           "RelationshipIndex":2,
                           "StoreGenerationIndex":2
                        },
                        "Getter":{

                        },
                        "Setter":{

                        },
                        "Accessors":{
                           "CurrentValueGetter":{
                              "Method":"System.String lambda_method(System.Runtime.CompilerServices.Closure, Microsoft.EntityFrameworkCore.ChangeTracking.Internal.InternalEntityEntry)",
                              "Target":{

                              }
                           },
                           "PreStoreGeneratedCurrentValueGetter":{
                              "Method":"System.String lambda_method(System.Runtime.CompilerServices.Closure, Microsoft.EntityFrameworkCore.ChangeTracking.Internal.InternalEntityEntry)",
                              "Target":{

                              }
                           },
                           "OriginalValueGetter":{
                              "Method":"System.String lambda_method(System.Runtime.CompilerServices.Closure, Microsoft.EntityFrameworkCore.ChangeTracking.Internal.InternalEntityEntry)",
                              "Target":{

                              }
                           },
                           "RelationshipSnapshotGetter":{
                              "Method":"System.String lambda_method(System.Runtime.CompilerServices.Closure, Microsoft.EntityFrameworkCore.ChangeTracking.Internal.InternalEntityEntry)",
                              "Target":{

                              }
                           },
                           "ValueBufferGetter":{
                              "Method":"System.Object lambda_method(System.Runtime.CompilerServices.Closure, Microsoft.EntityFrameworkCore.Storage.ValueBuffer)",
                              "Target":{

                              }
                           }
                        }
                     }
                  ],
                  "EntityType":{
                     "$ref":"7"
                  }
               },
               "OriginalValues":{
                  "Properties":[
                     {
                        "$ref":"8"
                     },
                     {
                        "$ref":"10"
                     },
                     {
                        "$ref":"16"
                     }
                  ],
                  "EntityType":{
                     "$ref":"7"
                  }
               }
            }
         ],
         "Type":"Microsoft.EntityFrameworkCore.DbUpdateException"
      }
   }
}

[RehanSaeed]

Thanks, that would be great!

I'm wondering if we could we use the Entity Framework SQLite provider for the tests.

[joelweiss]

Thanks, that would be great!

I'm wondering if we could we use the Entity Framework SQLite provider for the tests.

The SQLite provider doesn't set the DbUpdateException.Entries Property, so there was no new queries to the db.

[RehanSaeed]

PR has been merged. New NuGet package will be released soon. Closing issue.

[lesscodetxm]

@RehanSaeed Would there be a way to detect at runtime that Serilog.Exceptions.EntityFrameworkCore is not referenced, but the Serilog.Exceptions enricher is enabled? Maybe a warning-level log at initialization time, etc.

After we upgraded from .Net Core 2.2 -> 3.1 (and all associated third-party packages), we spent a lot of time tracking down our apparently random "out-of-memory" crashes because we were not aware of the new required package. I'd love to save the next person in this situation some time.

[RehanSaeed]

@lesscodetxm I think that's a good idea. It's there in the documentation but easy to miss.

We'd need to have a think about how we could log a warning using Serilog. It's a bit weird that logging something would cause another log message to get logged.

[lesscodetxm]

Well, I was thinking that the situation could be detected earlier than a logger call, maybe during .Enrich.WithExceptionDetails, but I guess there's no way to predict at that time that EF is going to try to log something...

[RehanSaeed]

We could look for the exception in the current assembly context on startup. However, we would take a slight performance hit. I'm not certain how much though.

[lesscodetxm]

Right. I was thinking that maybe it would be enough to warn if, during .Enrich.WithExceptionDetails, and the DbUpdateException destructurer wasn't configured, and the Microsoft.EntityFrameworkCore assembly is loaded, but the Serilog.Exceptions.EntityFrameworkCore assembly is not?

[RehanSaeed]

Yes that makes sense. Want to submit a small PR with that if statement in it?

[lesscodetxm]

I'll see if I can take a stab at it this week.

[lonix1]

Just ran into this, but thankfully not on production! :stuck_out_tongue:

I agree the developer should be informed, but not via a warning log - since this is a massive problem to have in production, it should crash the program on startup with an explanation and link to this issue.

[VictorioBerra]

I just had this problem, and it took me hours to track down. @lesscodetxm did you ever get around to a PR? What can we do to fix this? My entire DB started getting tracked when SaveChanges() failed. It knocked out the server memory.

[SeriousM]

It knocked out the server memory.

Ha, struggled to track this bug down for days... My issue was that a server exception was raised (data would be truncated..) and the reflectionbased exception deconstructor just went craaaazy by reading quite all data from database, thanks to lazy proxy usage. This raised other problems like the famous "open DataReader associated with this connection" which just made the problem much worse as we didn't know the original error message.

Using https://www.nuget.org/packages/Serilog.Exceptions.EntityFrameworkCore/ (and https://www.nuget.org/packages/Serilog.Exceptions.SqlServer/ ) fixed the problem.

[almostchristian]

Our project ran into this problem in production. It was not caught in testing because staging only had one instance whereas production had more than one which triggered the db conflict under load, specifically with data migration activities. We fixed this by adding Serilog.Exceptions.EntityFrameworkCore, however, I'm dissatisfied with the proposed solution of adding a warning or the current solution of adding a separate nuget package and adding in the destructorer. From what I see here, the issue stems from the ReflectionBasedDestructurer, performing the destructure on a DbContext instance. I'm thinking we can modify ReflectionInfoExtractor to filter any property of type assignable to DbContext (or DbSet) without requiring a separate nuget package.

If there is a reason to log the DbContext, an option would be to block the logging of DbSet, or IQueryable.

public ReflectionInfoExtractor()
{
    this.baseExceptionPropertiesForDestructuring = GetExceptionPropertiesForDestructuring(typeof(Exception));

    this.blockedTypes.Add(typeof(IQueryable));
}

private ReflectionInfo GenerateReflectionInfoForType(Type valueType)
{
    var properties = GetExceptionPropertiesForDestructuring(valueType);
    var propertyInfos = properties
        .Where(p => !this.blockedTypes.All(t => t.IsAssignableFrom(p.PropertyType)))
        .Select(p => new ReflectionPropertyInfo(p.Name, p.DeclaringType, GenerateFastGetterForProperty(valueType, p)))
        .ToArray();

[SeriousM]

The problem with this solution is that you need a type reference which causes a dependency on efcore. The reflectionbased deconstructor could just avoid dbcontext inherited and dbset based types (generic) by name, that would help. Adding the additional nuget package would lift the restriction and handle these exceptions gracefully.

[almostchristian]

Not true @SeriousM. If I call Type.GetType("Microsoft.EntityFrameworkCore.DbContext, Microsoft.EntityFrameworkCore") when Microsoft.EntityFrameworkCore is not referenced in the application, this will return a null. So the main Serilog.Exceptions does not need a reference to efcore. Anyway, I changed my sample code to use IQueryable instead. If serialization of IQueryable is blocked, this will prevent the serialization and enumeration of the DbSets, even if the DbContext is serialized.

The problem with requiring a separate nuget package is that it's so easy to miss. Also, there are also other implementations out there of IQueryable that is not tied to efcore. Execution of the underlying query provider can be an expensive operation, and I think it would make sense to block the serialization of any object that implements this interface, otherwise an expensive operation could be executed.

[almostchristian]

Another option is to give special handling to IQueryable objects so it doesn't enumerate, maybe just log the Expression property.

[almostchristian]

Here is my other proposal. This only requires modification to RelectionBasedDestructurer to give special handling of IQueryable values.

private static object DestructureQueryable(IQueryable value) => value.Expression.ToString();

// DestructureValue

    if (value is IQueryable queryable)
    {
        return DestructureQueryable(queryable);
    }
    else if (value is IEnumerable enumerable)
    {
        return this.DestructureValueEnumerable(enumerable, level, destructuredObjects, ref nextCyclicRefId);
    }

[RehanSaeed]

Here is my other proposal. This only requires modification to RelectionBasedDestructurer to give special handling of IQueryable values.

private static object DestructureQueryable(IQueryable value) => value.Expression.ToString();

// DestructureValue

    if (value is IQueryable queryable)
    {
        return DestructureQueryable(queryable);
    }
    else if (value is IEnumerable enumerable)
    {
        return this.DestructureValueEnumerable(enumerable, level, destructuredObjects, ref nextCyclicRefId);
    }

I like this solution as its a more general one as compared to special casing the exception in the core library. Thoughts @krajek?

[krajek]

If anything, I consider this one unobscure, safe improvement. @almostchristian are you keen on providing the PR? Let me know, if you can't I think I can implement one this week.

Note, that materialization of queries could be still present, for example in some getters' bodies. Then custom destructurers would be the only way to go.

[almostchristian]

Do you have concerns with the destructuring of the IQueryable using value.Expression.ToString()? IMO, it's not very useful unless we add something that can properly serialize the LINQ expression tree.