Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ObjectDisposedException on retrieval of a pooled DbContext #26202

Closed
alexyakunin opened this issue Sep 29, 2021 · 16 comments · Fixed by #26226
Closed

ObjectDisposedException on retrieval of a pooled DbContext #26202

alexyakunin opened this issue Sep 29, 2021 · 16 comments · Fixed by #26226
Assignees
Labels
area-dbcontext closed-fixed The issue has been fixed and is/will be included in the release indicated by the issue milestone. customer-reported regression Servicing-approved type-bug
Milestone

Comments

@alexyakunin
Copy link

EF Core version: 6.0.0-rc1
Database provider: any
Target framework: .NET 6.0
Operating system: any
IDE: any

https://github.com/dotnet/efcore/blob/release/6.0/src/EFCore/DbContext.cs#L902 - looks like _disposed field should be set to false here instead (and in the *Async version of the same method). The existing code causes any DbContext that was returned back to the pool to throw ObjectDisposedException on attempt to rent it again.

@alexyakunin alexyakunin changed the title ObjectDisposedException for pooled DbContexts in EF Core 6 ObjectDisposedException on retrieval of a once-disposed DbContext from PooledDbContextFactory in EF Core 6 Sep 29, 2021
alexyakunin added a commit to servicetitan/Stl.Fusion that referenced this issue Sep 29, 2021
@alexyakunin
Copy link
Author

alexyakunin commented Sep 29, 2021

alexyakunin added a commit to servicetitan/Stl.Fusion that referenced this issue Sep 29, 2021
@roji
Copy link
Member

roji commented Sep 29, 2021

@alexyakunin can you please submit a runnable code sample which shows exactly what you're doing to to get the ObjectDisposedException? The minimal code below works without any exceptions.

Attempted repro
var optionsBuilder = new DbContextOptionsBuilder<BlogContext>();
optionsBuilder
    .UseSqlServer(@"Server=localhost;Database=test;User=SA;Password=Abcd5678;Connect Timeout=60;ConnectRetryCount=0")
    .LogTo(Console.WriteLine, LogLevel.Information)
    .EnableSensitiveDataLogging();
var options = optionsBuilder.Options;

await using (var ctx = new BlogContext(options))
{
    await ctx.Database.EnsureDeletedAsync();
    await ctx.Database.EnsureCreatedAsync();
}

var factory = new PooledDbContextFactory<BlogContext>(options);

using (var ctx1 = factory.CreateDbContext())
{
    Console.WriteLine($"Context1 ID: {ctx1.ContextId}");
    _ = ctx1.Blogs.ToList();
}

using (var ctx2 = factory.CreateDbContext())
{
    Console.WriteLine($"Context2 ID: {ctx2.ContextId}");
    _ = ctx2.Blogs.ToList();
}

public class BlogContext : DbContext
{
    public DbSet<Blog> Blogs { get; set; }

    public BlogContext(DbContextOptions options) : base(options) {}
}

public class Blog
{
    public int Id { get; set; }
    public string Name { get; set; }
}

@alexyakunin
Copy link
Author

@roji sorry, I don't have enough time for this, but based on my description, you need a bit more than a basic example:

  • configure EF to use PooledDbContextFactory
  • run a loop that uses IDbContextFactory to create DbContext-s & instantly disposes them

This code should fail pretty quickly.

@alexyakunin
Copy link
Author

A short note about your code: I'd at least add a check that the second context is actually the same as the first one - otherwise you won't see the problem. I didn't dig into the pooling strategy, but since what's returned is actually up to the pool, it makes sense to at least check if the second attempt to rent the context produces the same instance.

@alexyakunin
Copy link
Author

One other thing is: I ended up thinking it's really a bug after I asked Rider to find every usage of DbContext._disposed field & noticed there is no single assignment of a false value there.

@alexyakunin
Copy link
Author

@alexyakunin
Copy link
Author

alexyakunin commented Sep 29, 2021

And the fix I referenced above killed all ObjectDisposedException-s, and the same test runs fine on .NET 5 build (with EF Core 5.*).

@roji
Copy link
Member

roji commented Sep 29, 2021

A short note about your code: I'd at least add a check that the second context is actually the same as the first one - otherwise you won't see the problem. I didn't dig into the pooling strategy, but since what's returned is actually up to the pool, it makes sense to at least check if the second attempt to rent the context produces the same instance.

That is what the outputting of the ContextId is about; the two GUIDs are identical, meaning that the same context instance is being reused.

One other thing is: I ended up thinking it's really a bug after I asked Rider to find every usage of DbContext._disposed field & noticed there is no single assignment of a false value there.

SetLeaseInternal sets _disposed to false. The way context pooling works is that when the context is disposed, it is placed more or less immediately back into the pool. Before it is handed out again (e.g. from PooledDbContextFactory.CreateDbContext), its state is reset and _disposed is set to false.

To summarize, I don't really see a bug at this point... I'm not saying there isn't one, but it's also possible to trigger an ObjectDisposedException through an application bug, e.g. if the same context instance is accidentally used concurrently from two threads. So some sort of code sample triggering this would be most helpful.

@roji
Copy link
Member

roji commented Sep 30, 2021

I managed to repro this in a concurrent tight-loop scenario, see code below. This only seems to repro when nothing is actually executed on the context. I'll investigate this for 6.0 in the coming days.

Stack trace
Task 7 reached iteration 999000
Unhandled exception. System.ObjectDisposedException: Cannot access a disposed context instance. A common cause of this error is disposing a context instance that was resolved from dependency injection and then later trying to use the same context instance elsewhere in your application. This may occur if you are calling 'Dispose' on the context instance, or wrapping it in a using statement. If you are using dependency injection, you should let the dependency injection container take care of disposing context instances.
Object name: 'BlogContext'.
   at Microsoft.EntityFrameworkCore.DbContext.CheckDisposed()
   at Microsoft.EntityFrameworkCore.DbContext.get_Database()
   at Microsoft.EntityFrameworkCore.DbContext.SetLeaseInternal(DbContextLease lease)
   at Microsoft.EntityFrameworkCore.DbContext.Microsoft.EntityFrameworkCore.Internal.IDbContextPoolable.SetLease(DbContextLease lease)
   at Microsoft.EntityFrameworkCore.Infrastructure.PooledDbContextFactory`1.CreateDbContext()
   at Program.<>c__DisplayClass0_1.<<Main>$>b__1() in /home/roji/projects/test/Program.cs:line 30
   at System.Threading.Tasks.Task.InnerInvoke()
   at System.Threading.Tasks.Task.<>c.<.cctor>b__271_0(Object obj)
   at System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(Thread threadPoolThread, ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location ---
   at System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(Thread threadPoolThread, ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot, Thread threadPoolThread)
--- End of stack trace from previous location ---
   at Program.<Main>$(String[] args) in /home/roji/projects/test/Program.cs:line 25
   at Program.<Main>(String[] args)
Repro
var optionsBuilder = new DbContextOptionsBuilder<BlogContext>();
optionsBuilder
    .UseSqlServer(@"Server=localhost;Database=test;User=SA;Password=Abcd5678;Connect Timeout=60;ConnectRetryCount=0");
var options = optionsBuilder.Options;

await using (var ctx = new BlogContext(options))
{
    await ctx.Database.EnsureDeletedAsync();
    await ctx.Database.EnsureCreatedAsync();
}

var factory = new PooledDbContextFactory<BlogContext>(options);

Console.WriteLine("Start");

await Task.WhenAll(
    Enumerable.Range(0, 10).Select(i => Task.Run(() =>
    {
        for (var j = 0; j < 1_000_000; j++)
        {
            using (var ctx1 = factory.CreateDbContext())
            {
                // _ = ctx1.Blogs.ToList();
            }

            if (j % 1_000 == 0)
                Console.WriteLine($"Task {i} reached iteration {j}");
        }
    })));

Console.WriteLine("Done");

public class BlogContext : DbContext
{
    public DbSet<Blog> Blogs { get; set; }

    public BlogContext(DbContextOptions options) : base(options) {}
}

public class Blog
{
    public int Id { get; set; }
    public string Name { get; set; }
}

@ajcvickers
Copy link
Member

@roji Race condition:

Context is disposed:

        public virtual void Dispose()
        {
            var leaseActive = _lease.IsActive;
            var contextDisposed = leaseActive && _lease.ContextDisposed();

            if (DisposeSync(leaseActive, contextDisposed))
            {
                _serviceScope?.Dispose();
            }
        }

Calls _lease.ContextDisposed();

        public bool ContextDisposed()
        {
            if (_standalone)
            {
                Release();

                return true;
            }

            return false;
        }

Context is now back in the pool. Back to Dispose method, DisposeSync is called:

        private bool DisposeSync(bool leaseActive, bool contextDisposed)
        {
            if (leaseActive)
            {
                if (contextDisposed)
                {
                    _disposed = true;
                    _lease = DbContextLease.InactiveLease;
                }
            }
...

Context is marked as disposed and lease is deactivated. But by this time the context may already have been pulled from the pool again, so we deactivate a context that is in use.

@alexyakunin
Copy link
Author

alexyakunin commented Oct 1, 2021

@roji , @ajcvickers , huge thanks - I also wanted to post a working example, but just got back to this & was pleasantly surprised!

@roji
Copy link
Member

roji commented Oct 1, 2021

Note: the same bug exists in 5.0.

@roji roji changed the title ObjectDisposedException on retrieval of a once-disposed DbContext from PooledDbContextFactory in EF Core 6 ObjectDisposedException on retrieval of a once-disposed DbContext from PooledDbContextFactory Oct 1, 2021
@roji roji changed the title ObjectDisposedException on retrieval of a once-disposed DbContext from PooledDbContextFactory ObjectDisposedException on retrieval of a pooled DbContext Oct 1, 2021
roji added a commit that referenced this issue Oct 1, 2021
@roji roji added the closed-fixed The issue has been fixed and is/will be included in the release indicated by the issue milestone. label Oct 1, 2021
roji added a commit that referenced this issue Oct 1, 2021
roji added a commit that referenced this issue Oct 1, 2021
roji added a commit that referenced this issue Oct 1, 2021
@ajcvickers
Copy link
Member

Note from triage: backport to EF Core 5.0.x, and possibly also to 3.1.x if it is also present there.

@ajcvickers ajcvickers added Servicing-consider and removed closed-fixed The issue has been fixed and is/will be included in the release indicated by the issue milestone. labels Oct 1, 2021
@roji
Copy link
Member

roji commented Oct 3, 2021

FYI I don't think this bug exists in 3.1 - it doesn't seem like the DbContext is mutated in any way after being returned to the pool (code).

@ajcvickers
Copy link
Member

@roji Can you prepare a PR cherry-picking this to 5.0.x?

roji added a commit that referenced this issue Oct 4, 2021
roji added a commit that referenced this issue Oct 4, 2021
Fixes #26202

(cherry picked from commit 8e09d65)
@roji
Copy link
Member

roji commented Oct 4, 2021

@ajcvickers #26241

roji added a commit that referenced this issue Oct 4, 2021
@ajcvickers ajcvickers added the closed-fixed The issue has been fixed and is/will be included in the release indicated by the issue milestone. label Oct 5, 2021
@ajcvickers ajcvickers added this to the 5.0.x milestone Oct 5, 2021
@ajcvickers ajcvickers reopened this Oct 5, 2021
ajcvickers pushed a commit that referenced this issue Oct 6, 2021
Fixes #26202

(cherry picked from commit 8e09d65)
@ajcvickers ajcvickers modified the milestones: 5.0.x, 5.0.12 Oct 6, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area-dbcontext closed-fixed The issue has been fixed and is/will be included in the release indicated by the issue milestone. customer-reported regression Servicing-approved type-bug
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants