efcore Cosmos: Optional One-To-Many relationship failing to explicit load (and improperly setting properties to null)

Issue

On EF Core 8.0.6 (and I also tried 9.0.0-preview.5.24306.3), I am trying to map a Dog optionally to a VetOfficeDoctor and when I request an explicit load on the Dog.VetOfficeDoctor relationship, EF Core clears/nulls the Dog.VetOfficeDoctorId and Dog.VetOfficeDoctor properties completely. The logs indicate the entity loads from Cosmos successfully, but it is detecting an incorrect change on these properties that sets them null.

On EF Core 7.0.20, this code is working correctly. I have also tried to explicitly configure these properties through the Model Builder instead of convention as shown in the code sample below, but that does not seem to help.

The only major behavior I'm noticing in the logs that is possibly different is that 8.0.6 is executing a ReadItem whereas 7.0.20 is building a NoSQL query - but obviously ReadItem is preferred for RU optimization:

EF Core 8.0.6:

info: 6/28/2024 12:06:15.032 CosmosEventId.ExecutingReadItem[30101] (Microsoft.EntityFrameworkCore.Database.Command)
      Reading resource 'VetOfficeDoctor|11d44b84-81cf-4bd4-af1e-08dc97949da4' item from container 'OptionalOneToManyFailDbContext' in partition '(null)'.
info: 6/28/2024 12:06:15.443 CosmosEventId.ExecutedReadItem[30103] (Microsoft.EntityFrameworkCore.Database.Command)
      Executed ReadItem (411 ms, 1 RU) ActivityId='94049864-6456-4b01-bd35-c72239e54232', Container='OptionalOneToManyFailDbContext', Id='VetOfficeDoctor|11d44b84-81cf-4bd4-af1e-08dc97949da4', Partition='(null)'

EF Core 7.0.20:

info: 6/28/2024 12:16:34.073 CosmosEventId.ExecutingSqlQuery[30100] (Microsoft.EntityFrameworkCore.Database.Command)
      Executing SQL query for container 'OptionalOneToManyFailDbContext' in partition '(null)' [Parameters=[@__get_Item_0='0c184ebd-7a4e-420d-67d8-08dc97960e4a']]
      SELECT c
      FROM root c
      WHERE ((c["Discriminator"] = "VetOfficeDoctor") AND (c["Id"] = @__get_Item_0))
info: 6/28/2024 12:16:34.167 CosmosEventId.ExecutedReadNext[30102] (Microsoft.EntityFrameworkCore.Database.Command)
      Executed ReadNext (93.1454 ms, 2.93 RU) ActivityId='dd75eb59-f993-404f-bd4e-f6fc43186108', Container='OptionalOneToManyFailDbContext', Partition='(null)', Parameters=[@__get_Item_0='0c184ebd-7a4e-420d-67d8-08dc97960e4a']
      SELECT c
      FROM root c
      WHERE ((c["Discriminator"] = "VetOfficeDoctor") AND (c["Id"] = @__get_Item_0))

EF Core 8.0.6 output:

VetOfficeDoctorId before load: 11d44b84-81cf-4bd4-af1e-08dc97949da4
VetOfficeDoctorId after load:
Vet Office Doctor not found!
Vet Office Doctor Id not found!

EF Core 7.0.20 output (expected):

VetOfficeDoctorId before load: c6208d9d-1c4f-4ad5-ab5d-08dc97923e47
VetOfficeDoctorId after load: c6208d9d-1c4f-4ad5-ab5d-08dc97923e47
Vet Office Doctor found! - Vet Id: c6208d9d-1c4f-4ad5-ab5d-08dc97923e47 - Name: Test Doctor
Vet Office Doctor Id found! - Vet Id: c6208d9d-1c4f-4ad5-ab5d-08dc97923e47

Failing Code Sample

using Microsoft.EntityFrameworkCore;

Guid insertedDog = Guid.Empty;
Guid insertedVetOfficeDoctor = Guid.Empty;

using (var db = new OptionalOneToManyFailDbContext())
{
    await db.Database.EnsureCreatedAsync();
    VetOfficeDoctor vetOfficeDoctor = new() { Name = "Test Doctor" };
    Dog dog = new() { Name = "Test Dog", VetOfficeDoctor = vetOfficeDoctor };
    db.Dogs.Add(dog);
    await db.SaveChangesAsync();
    insertedDog = dog.Id;
    insertedVetOfficeDoctor = vetOfficeDoctor.Id;
}

using (var db = new OptionalOneToManyFailDbContext())
{
    var foundDog = await db.Dogs.FindAsync(insertedDog) ?? throw new Exception("Could not find Dog with Id: " + insertedDog);
    Console.WriteLine("VetOfficeDoctorId before load: " + foundDog.VetOfficeDoctorId);

    await db.Entry(foundDog).Reference(x => x.VetOfficeDoctor).LoadAsync();
    Console.WriteLine("VetOfficeDoctorId after load: " + foundDog.VetOfficeDoctorId);

    if (foundDog.VetOfficeDoctor is null)
        Console.WriteLine("Vet Office Doctor not found!");
    else
        Console.WriteLine($"Vet Office Doctor found! - Vet Id: {foundDog.VetOfficeDoctor.Id} - Name: {foundDog.VetOfficeDoctor.Name}");

    if (foundDog.VetOfficeDoctorId is null)
        Console.WriteLine("Vet Office Doctor Id not found!");
    else
        Console.WriteLine($"Vet Office Doctor Id found! - Vet Id: {foundDog.VetOfficeDoctorId}");
}

public class OptionalOneToManyFailDbContext : DbContext
{
    public DbSet<Dog> Dogs => Set<Dog>();
    public DbSet<VetOfficeDoctor> VetOfficeDoctors => Set<VetOfficeDoctor>();

    protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
        => optionsBuilder.UseCosmos(
            "https://localhost:443/",
            "cosmos-key",
            "FailDbTest").EnableSensitiveDataLogging(true).LogTo(x => Console.WriteLine(x));
}

public class Dog
{
    public Guid Id { get; set; }
    public string Name { get; set; } = string.Empty;
    public VetOfficeDoctor? VetOfficeDoctor { get; set; }
    public Guid? VetOfficeDoctorId { get; set; }
}

public class VetOfficeDoctor
{
    public Guid Id { get; set; }
    public string Name { get; set; } = string.Empty;
    public ICollection<Dog> Dogs { get; set; } = [];
}

provider and version information

EF Core version: 8.0.6 and 9.0.0-preview.5.24306.3 fail, 7.0.20 succeeds. Database provider: Microsoft.EntityFrameworkCore.Cosmos Target framework: .NET 8 Operating system: Windows 11 IDE: Visual Studio 2022 17.10.1

Jun 28 '24 17:06 brused27

In further troubleshooting on attempting to find a workaround, I am able to cause the entity relationship to load properly if I trigger a SqlQuery to run instead of letting EF Core attempt a ReadItem request by replacing the explicit load line in the sample code above:

await db.Entry(foundDog).Reference(x => x.VetOfficeDoctor).LoadAsync();

and update it to:

await db.VetOfficeDoctors.Where(x => x.Id == foundDog.VetOfficeDoctorId).FirstAsync();

This causes the relationship to load properly and retains the information as expected, so this bug does seem to be something associated with the newer ReadItem behavior.

Jun 28 '24 17:06 brused27

Note for team: this still repros on the latest daily build.

Jul 15 '24 17:07 ajcvickers

Verified that this is fixed in the latest daily build.

Output from EF8:

C:\Users\avickers\AppData\Local\Programs\Rider\plugins\dpa\DotFiles\JetBrains.DPA.Runner.exe --handle=22604 --backend-pid=53540 --etw-collect-flags=67108622 --detach-event-name=dpa.detach.22604 D:/code/AllTogetherNow/One/bin/Debug/net8.0/One.exe
warn: 7/29/2024 15:27:25.149 CoreEventId.SensitiveDataLoggingEnabledWarning[10400] (Microsoft.EntityFrameworkCore.Infrastructure) 
      Sensitive data logging is enabled. Log entries and exception messages may include sensitive application data; this mode should only be enabled during development.
info: 7/29/2024 15:27:28.873 CosmosEventId.ExecutedCreateItem[30104] (Microsoft.EntityFrameworkCore.Database.Command) 
      Executed CreateItem (127 ms, 7.05 RU) ActivityId='9b1115db-43b3-491b-ae56-3d1a4cdaf301', Container='OptionalOneToManyFailDbContext', Id='Dog|5f0063f2-f63e-4768-30ac-08dcafda9321', Partition='(null)'
info: 7/29/2024 15:27:28.892 CosmosEventId.ExecutedCreateItem[30104] (Microsoft.EntityFrameworkCore.Database.Command) 
      Executed CreateItem (10 ms, 6.67 RU) ActivityId='00c96878-17c5-4b89-9602-1bf927036734', Container='OptionalOneToManyFailDbContext', Id='VetOfficeDoctor|20dce496-5d70-4b01-0868-08dcafda932b', Partition='(null)'
info: 7/29/2024 15:27:29.076 CosmosEventId.ExecutingReadItem[30101] (Microsoft.EntityFrameworkCore.Database.Command) 
      Reading resource 'Dog|5f0063f2-f63e-4768-30ac-08dcafda9321' item from container 'OptionalOneToManyFailDbContext' in partition '(null)'.
info: 7/29/2024 15:27:29.092 CosmosEventId.ExecutedReadItem[30103] (Microsoft.EntityFrameworkCore.Database.Command) 
      Executed ReadItem (7 ms, 1 RU) ActivityId='03293c84-230c-47f9-81db-f716a9ba9fed', Container='OptionalOneToManyFailDbContext', Id='Dog|5f0063f2-f63e-4768-30ac-08dcafda9321', Partition='(null)'
VetOfficeDoctorId before load: 20dce496-5d70-4b01-0868-08dcafda932b
info: 7/29/2024 15:27:29.118 CosmosEventId.ExecutingReadItem[30101] (Microsoft.EntityFrameworkCore.Database.Command) 
      Reading resource 'VetOfficeDoctor|20dce496-5d70-4b01-0868-08dcafda932b' item from container 'OptionalOneToManyFailDbContext' in partition '(null)'.
info: 7/29/2024 15:27:29.120 CosmosEventId.ExecutedReadItem[30103] (Microsoft.EntityFrameworkCore.Database.Command) 
      Executed ReadItem (1 ms, 1 RU) ActivityId='565ab114-9716-4378-8290-b7438a02c6a5', Container='OptionalOneToManyFailDbContext', Id='VetOfficeDoctor|20dce496-5d70-4b01-0868-08dcafda932b', Partition='(null)'
VetOfficeDoctorId after load: 
Vet Office Doctor not found!
Vet Office Doctor Id not found!

Output from EF9:

C:\Users\avickers\AppData\Local\Programs\Rider\plugins\dpa\DotFiles\JetBrains.DPA.Runner.exe --handle=23284 --backend-pid=53540 --etw-collect-flags=67108622 --detach-event-name=dpa.detach.23284 D:/code/AllTogetherNow/One/bin/Debug/net8.0/One.exe
warn: 7/29/2024 15:28:44.731 CoreEventId.SensitiveDataLoggingEnabledWarning[10400] (Microsoft.EntityFrameworkCore.Infrastructure) 
      Sensitive data logging is enabled. Log entries and exception messages may include sensitive application data; this mode should only be enabled during development.
warn: 7/29/2024 15:28:44.750 CosmosEventId.NoPartitionKeyDefined[30600] (Microsoft.EntityFrameworkCore.Model.Validation) 
      No partition key has been configured for entity type 'Dog'. It is highly recommended that an appropriate partition key be defined. See https://aka.ms/efdocs-cosmos-partition-keys for more information.
warn: 7/29/2024 15:28:44.750 CosmosEventId.NoPartitionKeyDefined[30600] (Microsoft.EntityFrameworkCore.Model.Validation) 
      No partition key has been configured for entity type 'VetOfficeDoctor'. It is highly recommended that an appropriate partition key be defined. See https://aka.ms/efdocs-cosmos-partition-keys for more information.
info: 7/29/2024 15:28:48.252 CosmosEventId.ExecutedCreateItem[30104] (Microsoft.EntityFrameworkCore.Database.Command) 
      Executed CreateItem (119 ms, 7.05 RU) ActivityId='13e83ee4-fa6a-4683-a276-b1c4b28c69ef', Container='OptionalOneToManyFailDbContext', Id='Dog|e5671f8c-8efb-45a0-fc03-08dcafdac272', Partition='None'
info: 7/29/2024 15:28:48.273 CosmosEventId.ExecutedCreateItem[30104] (Microsoft.EntityFrameworkCore.Database.Command) 
      Executed CreateItem (12 ms, 6.67 RU) ActivityId='9aa72215-d1e4-4cd9-be2f-771fb5860878', Container='OptionalOneToManyFailDbContext', Id='VetOfficeDoctor|a189508d-4ab0-4a80-7511-08dcafdac27d', Partition='None'
info: 7/29/2024 15:28:48.495 CosmosEventId.ExecutingReadItem[30101] (Microsoft.EntityFrameworkCore.Database.Command) 
      Reading resource 'Dog|e5671f8c-8efb-45a0-fc03-08dcafdac272' item from container 'OptionalOneToManyFailDbContext' in partition 'None'.
info: 7/29/2024 15:28:48.512 CosmosEventId.ExecutedReadItem[30103] (Microsoft.EntityFrameworkCore.Database.Command) 
      Executed ReadItem (7 ms, 1 RU) ActivityId='f096eacd-0f79-48f7-adcd-e09cf54f42da', Container='OptionalOneToManyFailDbContext', Id='Dog|e5671f8c-8efb-45a0-fc03-08dcafdac272', Partition='None'
VetOfficeDoctorId before load: a189508d-4ab0-4a80-7511-08dcafdac27d
info: 7/29/2024 15:28:48.531 CosmosEventId.ExecutingReadItem[30101] (Microsoft.EntityFrameworkCore.Database.Command) 
      Reading resource 'VetOfficeDoctor|a189508d-4ab0-4a80-7511-08dcafdac27d' item from container 'OptionalOneToManyFailDbContext' in partition 'None'.
info: 7/29/2024 15:28:48.533 CosmosEventId.ExecutedReadItem[30103] (Microsoft.EntityFrameworkCore.Database.Command) 
      Executed ReadItem (1 ms, 1 RU) ActivityId='ed7ba1dd-594b-4c97-8450-8486e1f94fd3', Container='OptionalOneToManyFailDbContext', Id='VetOfficeDoctor|a189508d-4ab0-4a80-7511-08dcafdac27d', Partition='None'
VetOfficeDoctorId after load: a189508d-4ab0-4a80-7511-08dcafdac27d
Vet Office Doctor found! - Vet Id: a189508d-4ab0-4a80-7511-08dcafdac27d - Name: Test Doctor
Vet Office Doctor Id found! - Vet Id: a189508d-4ab0-4a80-7511-08dcafdac27d

Jul 29 '24 14:07 ajcvickers