[CosmosDB] Concurrency token isn't updated when an embedded entity is modified

[anttikes]

Include your code

A sample application which reproduces the issue is attached below. The project attempts to connect to a CosmosDB emulator running on the local computer. This problem scenario has not been tested against a real Azure CosmosDB account but similar behavior in an existing application has been observed there as well. The problem seems to be in EF Core itself.

The sample solution contains a container entity, a child entity and a DbContext-derived class acting as the context.

cosmosdb-nested-entities-issue.zip

Include provider and version information

EF Core version: 5.0.12
Database provider: Microsoft.EntityFrameworkCore.Cosmos
Database provider version: 5.0.12
Underlying Azure SDK version: 3.12.0
Target framework: .NET 5.0
Operating system: Windows 10 Enterprise (version "10.0.19043 Build 19043")
IDE: Visual Studio 2019 version 16.11.5
CosmosDB Emulator version: 2.14.2.0 (ed0413c7)
Operating system time zone settings: "UTC+02:00 Helsinki, Kyiv, Riga, Sofia, Tallinn, Vilnius"

Reproduction steps

1. Open up the sample application in Visual Studio
2. Build it
3. Run it

Observed result

As seen from the console output of the program, the ETag value of the DummyContainer entity is not updated correctly after the second SaveChangesAsync is called. An explicit ReloadAsync is required in order for the new value to be present in the entity's property.

Recreating database
--------------------

Creating new entity
--------------------

ETag from entity after saving: "00000000-0000-0000-d6e6-20c4838401d7"

Modifying existing entity
--------------------------

ETag from entity before changes: "00000000-0000-0000-d6e6-20c4838401d7"

ETag from entity after saving: "00000000-0000-0000-d6e6-20c4838401d7"

Refreshing entity from context
-------------------------------

ETag from entity after reload: "00000000-0000-0000-d6e6-2119b53401d7"

The following DebugView extract shows that before the ReloadAsync call, the updated ETag value is available in the change tracker but for some reason or another the change does not "swim up" to the property:

DummyContainer {Id: b50368fe-2d1d-4b5d-a80a-75eb0ea21a34} Modified
  Id: 'b50368fe-2d1d-4b5d-a80a-75eb0ea21a34' PK
  ETag: '"00000000-0000-0000-d6e6-2119b53401d7"' Modified Originally '"00000000-0000-0000-d6e6-20c4838401d7"'
  __id: 'DummyContainer|b50368fe-2d1d-4b5d-a80a-75eb0ea21a34' AK
  __jObject: '{
  "Id": "b50368fe-2d1d-4b5d-a80a-75eb0ea21a34",
  "_etag...' Modified Originally '{
  "Id": "b50368fe-2d1d-4b5d-a80a-75eb0ea21a34",
  "_etag...'
  type: 'DummyContainer' AK
  Children: [....]

Furthermore, attempting to perform multiple SaveChangesAsync calls will result in a concurrency exception. Most likely in the second save call EF Core attempts to send the previous ETag value from the entity, and the CosmosDB emulator then correctly declines the action. EF Core then proceeds to operate correctly and throws the exception.

Attempting to modify entity twice with one context
--------------------------------------------------

Adding child

Saving...

Adding another child

Saving again...

Unhandled exception. Microsoft.EntityFrameworkCore.DbUpdateConcurrencyException: Conflicts were detected for item with id 'DummyContainer|c4d95053-442d-4c0f-8819-bc7ce65341c9'.

The full exception stack trace is as follows:

Unhandled exception. Microsoft.EntityFrameworkCore.DbUpdateConcurrencyException: Conflicts were detected for item with id 'DummyContainer|c4d95053-442d-4c0f-8819-bc7ce65341c9'.
 ---> Microsoft.Azure.Cosmos.CosmosException : Response status code does not indicate success: PreconditionFailed (412); Substatus: 0; ActivityId: 611d8043-ea99-4530-bfc1-30d42b6f2994; Reason: ({
  "Errors": [
    "One of the specified pre-condition is not met"
  ]
});
   at Microsoft.Azure.Cosmos.ResponseMessage.EnsureSuccessStatusCode()
   at Microsoft.EntityFrameworkCore.Cosmos.Storage.Internal.CosmosClientWrapper.ProcessResponse(ResponseMessage response, IUpdateEntry entry)
   at Microsoft.EntityFrameworkCore.Cosmos.Storage.Internal.CosmosClientWrapper.ReplaceItemOnceAsync(DbContext _, ValueTuple`4 parameters, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Cosmos.Storage.Internal.CosmosDatabaseWrapper.SaveChangesAsync(IList`1 entries, CancellationToken cancellationToken)
--- Cosmos Diagnostics ---{"DiagnosticVersion":"2","Summary":{"StartUtc":"2021-11-11T10:04:39.9594314Z","TotalElapsedTimeInMs":5.0192,"UserAgent":"cosmos-netstandard-sdk/3.12.0|3.11.4|01|X64|Microsoft Windows 10.0.19043|.NET 5.0.12| Microsoft.EntityFrameworkCore.Cosmos/5.0.12","TotalRequestCount":1,"FailedRequestCount":1},"Context":[{"Id":"Microsoft.Azure.Cosmos.Handlers.DiagnosticsHandler","HandlerElapsedTimeInMs":4.9631},{"Id":"SystemInfo","CpuHistory":"(2021-11-11T10:04:37.5882227Z 58.333)"},{"Id":"Microsoft.Azure.Cosmos.Handlers.RetryHandler","HandlerElapsedTimeInMs":4.9584},{"Id":"Microsoft.Azure.Cosmos.Handlers.RouterHandler","HandlerElapsedTimeInMs":2.2974},{"Id":"Microsoft.Azure.Cosmos.Handlers.TransportHandler","HandlerElapsedTimeInMs":1.2335},{"Id":"AggregatedClientSideRequestStatistics","ContactedReplicas":[{"Count":12,"Uri":"rntbd://10.26.10.2:10253/apps/DocDbApp/services/DocDbServer23/partitions/a4cb4963-38c8-11e6-8106-8cdcd42c33be/replicas/1p/"}],"RegionsContacted":["https://10.26.10.2:8081/"],"FailedReplicas":[]},{"Id":"Microsoft.Azure.Documents.ServerStoreModel","ElapsedTimeInMs":1.7149},{"Id":"StoreResponseStatistics","StartTimeUtc":"2021-11-11T10:04:39.9595338Z","ResponseTimeUtc":"2021-11-11T10:04:39.9607869Z","ElapsedTimeInMs":1.2531,"ResourceType":"Document","OperationType":"Replace","LocationEndpoint":"https://10.26.10.2:8081/","ActivityId":"611d8043-ea99-4530-bfc1-30d42b6f2994","StoreResult":"StorePhysicalAddress: rntbd://10.26.10.2:10253/apps/DocDbApp/services/DocDbServer23/partitions/a4cb4963-38c8-11e6-8106-8cdcd42c33be/replicas/1p/, LSN: 179, GlobalCommittedLsn: -1, PartitionKeyRangeId: 0, IsValid: True, StatusCode: 412, SubStatusCode: 0, RequestCharge: 1.24, ItemLSN: -1, SessionToken: -1#179, UsingLocalLSN: False, TransportException: null"}]}
   --- End of inner exception stack trace ---
   at Microsoft.EntityFrameworkCore.Cosmos.Storage.Internal.CosmosDatabaseWrapper.ThrowUpdateException(CosmosException exception, IUpdateEntry entry)
   at Microsoft.EntityFrameworkCore.Cosmos.Storage.Internal.CosmosDatabaseWrapper.SaveChangesAsync(IList`1 entries, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChangesAsync(IList`1 entriesToSave, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChangesAsync(DbContext _, Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Storage.ExecutionStrategy.ExecuteImplementationAsync[TState,TResult](Func`4 operation, Func`4 verifySucceeded, TState state, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Storage.ExecutionStrategy.ExecuteImplementationAsync[TState,TResult](Func`4 operation, Func`4 verifySucceeded, TState state, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.DbContext.SaveChangesAsync(Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.DbContext.SaveChangesAsync(Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken)
   at cosmosdb_nested_entities_issue.Program.Main() in C:\Work\cosmosdb-nested-entities-issue\cosmosdb-nested-entities-issue\Program.cs:line 168
   at cosmosdb_nested_entities_issue.Program.<Main>()

Expected result

The expected outcome of the whole program is that there is no need to call ReloadAsync in order to update the entity's ETag
property. Furthermore, it is expected that consecutive SaveChangesAsync calls will not throw an exception.

Further notes

This issue has been tested with Entity Framework 6.0.0 as well. Since I do not have Visual Studio 2022 installed I was forced to use the command line tools. The only difference seems to be that the ETag value after the second SaveChangesAsync is set to null or an empty string. I cannot debug the solution so I do not know for sure.

Otherwise things like change tracker output remain the same with EF Core 6.0.0