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

Microsoft.Data.Sqlite.SqliteConnectionPool.GetConnection() fails with "Inconceivable!" on local test run #26016

Closed
Tracked by #30173
ajcvickers opened this issue Sep 14, 2021 · 5 comments · Fixed by #32615
Assignees
Labels
area-adonet-sqlite area-groupby closed-fixed The issue has been fixed and is/will be included in the release indicated by the issue milestone. punted-for-6.0 punted-for-7.0 Originally planned for the EF Core 7.0 (EF7) release, but moved out due to resource constraints. type-bug

Comments

@ajcvickers
Copy link
Member

xUnit.net Console Runner v2.4.1 (64-bit .NET 6.0.0-rc.1.21378.2)
  Discovering: Microsoft.EntityFrameworkCore.Sqlite.FunctionalTests
  Discovered:  Microsoft.EntityFrameworkCore.Sqlite.FunctionalTests
  Starting:    Microsoft.EntityFrameworkCore.Sqlite.FunctionalTests
    Microsoft.EntityFrameworkCore.Query.NorthwindGroupByQuerySqliteTest.GroupBy_with_group_key_being_navigation_with_complex_projection [SKIP]
      issue #15938
    Microsoft.EntityFrameworkCore.Query.NorthwindWhereQuerySqliteTest.Where_compare_tuple_constructed_multi_value_not_equal [SKIP]
      Issue #14672
    Microsoft.EntityFrameworkCore.Query.IncompleteMappingInheritanceQuerySqliteTest.Union_entity_equality [SKIP]
      Issue#16298
    Microsoft.EntityFrameworkCore.Query.GearsOfWarQuerySqliteTest.Where_TimeOnly_subtract_TimeOnly [SKIP]
      #18844
    Microsoft.EntityFrameworkCore.Query.GearsOfWarQuerySqliteTest.Include_on_GroupJoin_SelectMany_DefaultIfEmpty_with_conditional_result [SKIP]
      Issue#15783
    Microsoft.EntityFrameworkCore.Query.IncompleteMappingInheritanceQuerySqliteTest.OfType_Union_subquery [SKIP]
      Issue#16298
    Microsoft.EntityFrameworkCore.Query.GearsOfWarQuerySqliteTest.Correlated_collections_with_Skip [SKIP]
      Issue#16313
    Microsoft.EntityFrameworkCore.Query.IncompleteMappingInheritanceQuerySqliteTest.OfType_Union_OfType [SKIP]
      Issue#16298
    Microsoft.EntityFrameworkCore.Query.NorthwindIncludeQuerySqliteTest.Include_collection_OrderBy_empty_list_does_not_contains [SKIP]
      Issue#15713
    Microsoft.EntityFrameworkCore.Query.IncompleteMappingInheritanceQuerySqliteTest.Union_siblings_with_duplicate_property_in_subquery [SKIP]
      Issue#16298
    Microsoft.EntityFrameworkCore.TPTTableSplittingSqliteTest.Can_insert_dependent_with_just_one_parent [SKIP]
      Issue #24970
    Microsoft.EntityFrameworkCore.Query.GearsOfWarQuerySqliteTest.Nav_rewrite_Distinct_with_convert [SKIP]
      Issue #17328
    Microsoft.EntityFrameworkCore.Query.GearsOfWarQuerySqliteTest.Navigation_based_on_complex_expression6 [SKIP]
      issue #17782
    Microsoft.EntityFrameworkCore.Query.GearsOfWarQuerySqliteTest.Where_TimeOnly_Minute [SKIP]
      #18844
    Microsoft.EntityFrameworkCore.Query.TPTManyToManyNoTrackingQuerySqliteTest.Includes_accessed_via_different_path_are_merged [SKIP]
      Issue#21332
    Microsoft.EntityFrameworkCore.Query.GearsOfWarQuerySqliteTest.TimeSpan_Hours [SKIP]
      Issue#18844
    Microsoft.EntityFrameworkCore.Query.TPTManyToManyNoTrackingQuerySqliteTest.Filered_includes_accessed_via_different_path_are_merged [SKIP]
      Issue#21332
    Microsoft.EntityFrameworkCore.Query.NorthwindKeylessEntitiesQuerySqliteTest.KeylessEntity_with_nav_defining_query [SKIP]
      Issue#21627
    Microsoft.EntityFrameworkCore.Query.TPTManyToManyNoTrackingQuerySqliteTest.Throws_when_different_filtered_then_include_via_different_paths [SKIP]
      Issue#21332
    Microsoft.EntityFrameworkCore.Query.GearsOfWarQuerySqliteTest.Where_TimeOnly_IsBetween [SKIP]
      #18844
    Microsoft.EntityFrameworkCore.Query.GearsOfWarQuerySqliteTest.Anonymous_projection_take_followed_by_projecting_single_element_from_collection_navigation [SKIP]
      issue #12603
    Microsoft.EntityFrameworkCore.TableSplittingSqliteTest.Can_insert_dependent_with_just_one_parent [SKIP]
      Issue #24970
    Microsoft.EntityFrameworkCore.Query.GearsOfWarQuerySqliteTest.Include_on_GroupJoin_SelectMany_DefaultIfEmpty_with_complex_projection_result [SKIP]
      issue #16899
    Microsoft.EntityFrameworkCore.GraphUpdatesSqliteChangedChangingNotificationsTest.Clearing_shadow_key_owned_collection_throws [SKIP]
      Default owned collection pattern does not work with SQLite due to composite key.
    Microsoft.EntityFrameworkCore.Query.GearsOfWarQuerySqliteTest.Filter_on_subquery_projecting_one_value_type_from_empty_collection [SKIP]
      issue #15864
    Microsoft.EntityFrameworkCore.Query.GearsOfWarQuerySqliteTest.Orderby_added_for_client_side_GroupJoin_composite_dependent_to_principal_LOJ_when_incomplete_key_is_used [SKIP]
      Issue #17328
    Microsoft.EntityFrameworkCore.Query.NorthwindSelectQuerySqliteTest.Collection_FirstOrDefault_with_entity_equality_check_in_projection [SKIP]
      Issue#12148
Process terminated. Assertion failed.
Inconceivable!
   at Microsoft.Data.Sqlite.SqliteConnectionPool.GetConnection() in C:\dotnet\efcore\src\Microsoft.Data.Sqlite.Core\SqliteConnectionPool.cs:line 58
   at Microsoft.Data.Sqlite.SqliteConnectionFactory.GetConnection(SqliteConnection outerConnection) in C:\dotnet\efcore\src\Microsoft.Data.Sqlite.Core\SqliteConnectionFactory.cs:line 37
   at Microsoft.Data.Sqlite.SqliteConnection.Open() in C:\dotnet\efcore\src\Microsoft.Data.Sqlite.Core\SqliteConnection.cs:line 193
   at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.OpenDbConnection(Boolean errorsExpected) in C:\dotnet\efcore\src\EFCore.Relational\Storage\RelationalConnection.cs:line 751
   at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.OpenInternal(Boolean errorsExpected) in C:\dotnet\efcore\src\EFCore.Relational\Storage\RelationalConnection.cs:line 729
   at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.Open(Boolean errorsExpected) in C:\dotnet\efcore\src\EFCore.Relational\Storage\RelationalConnection.cs:line 636
   at Microsoft.EntityFrameworkCore.Migrations.Internal.MigrationCommandExecutor.ExecuteNonQuery(IEnumerable`1 migrationCommands, IRelationalConnection connection) in C:\dotnet\efcore\src\EFCore.Relational\Migrations\Internal\MigrationCommandExecutor.cs:line 53
   at Microsoft.EntityFrameworkCore.Storage.RelationalDatabaseCreator.CreateTables() in C:\dotnet\efcore\src\EFCore.Relational\Storage\RelationalDatabaseCreator.cs:line 130
   at Microsoft.EntityFrameworkCore.TestUtilities.RelationalDatabaseCleaner.Clean(DatabaseFacade facade) in C:\dotnet\efcore\test\EFCore.Relational.Specification.Tests\TestUtilities\RelationalDatabaseCleaner.cs:line 116
   at Microsoft.EntityFrameworkCore.TestUtilities.SqliteDatabaseCleaner.Clean(DatabaseFacade facade) in C:\dotnet\efcore\test\EFCore.Sqlite.FunctionalTests\TestUtilities\SqliteDatabaseCleaner.cs:line 83
   at Microsoft.EntityFrameworkCore.SqliteDatabaseFacadeTestExtensions.EnsureClean(DatabaseFacade databaseFacade) in C:\dotnet\efcore\test\EFCore.Sqlite.FunctionalTests\SqliteDatabaseFacadeTestExtensions.cs:line 12
   at Microsoft.EntityFrameworkCore.TestUtilities.SqliteTestStore.Clean(DbContext context) in C:\dotnet\efcore\test\EFCore.Sqlite.FunctionalTests\TestUtilities\SqliteTestStore.cs:line 88
   at Microsoft.EntityFrameworkCore.TestUtilities.SqliteTestStore.Initialize(Func`1 createContext, Action`1 seed, Action`1 clean) in C:\dotnet\efcore\test\EFCore.Sqlite.FunctionalTests\TestUtilities\SqliteTestStore.cs:line 81
   at Microsoft.EntityFrameworkCore.TestUtilities.TestStore.<>c__DisplayClass13_0.<Initialize>b__0() in C:\dotnet\efcore\test\EFCore.Specification.Tests\TestUtilities\TestStore.cs:line 41
   at Microsoft.EntityFrameworkCore.TestUtilities.TestStoreIndex.CreateShared(String name, Action initializeDatabase) in C:\dotnet\efcore\test\EFCore.Specification.Tests\TestUtilities\TestStoreIndex.cs:line 28
   at Microsoft.EntityFrameworkCore.TestUtilities.TestStore.Initialize(IServiceProvider serviceProvider, Func`1 createContext, Action`1 seed, Action`1 clean) in C:\dotnet\efcore\test\EFCore.Specification.Tests\TestUtilities\TestStore.cs:line 41
   at Microsoft.EntityFrameworkCore.TestUtilities.RelationalTestStore.Initialize(IServiceProvider serviceProvider, Func`1 createContext, Action`1 seed, Action`1 clean) in C:\dotnet\efcore\test\EFCore.Relational.Specification.Tests\TestUtilities\RelationalTestStore.cs:line 43
   at Microsoft.EntityFrameworkCore.SharedStoreFixtureBase`1.InitializeAsync() in C:\dotnet\efcore\test\EFCore.Specification.Tests\SharedStoreFixtureBase.cs:line 65
   at Xunit.Sdk.ExceptionAggregator.RunAsync(Func`1 code) in C:\Dev\xunit\xunit\src\xunit.core\Sdk\ExceptionAggregator.cs:line 90
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine) in System.Private.CoreLib.dll:token 0x6004ee8+0x28
   at Xunit.Sdk.ExceptionAggregator.RunAsync(Func`1 code) in xunit.core.dll:token 0x6000070+0x2b
   at Xunit.Sdk.XunitTestClassRunner.<CreateClassFixtureAsync>b__11_1(IAsyncLifetime fixture) in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\Runners\XunitTestClassRunner.cs:line 105
   at System.Linq.Enumerable.SelectListIterator`2.MoveNext() in System.Linq.dll:token 0x60001e7+0x36
   at System.Threading.Tasks.Task.WhenAll(IEnumerable`1 tasks) in System.Private.CoreLib.dll:token 0x60032e0+0xa8
   at Xunit.Sdk.XunitTestClassRunner.CreateClassFixtureAsync(Type fixtureType) in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\Runners\XunitTestClassRunner.cs:line 105
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine) in System.Private.CoreLib.dll:token 0x6004ee8+0x28
   at Xunit.Sdk.XunitTestClassRunner.CreateClassFixtureAsync(Type fixtureType) in xunit.execution.dotnet.dll:token 0x600015a+0x2b
   at Xunit.Sdk.XunitTestClassRunner.AfterTestClassStartingAsync() in xunit.execution.dotnet.dll:token 0x600015c+0x0
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine) in System.Private.CoreLib.dll:token 0x6004ee8+0x28
   at Xunit.Sdk.XunitTestClassRunner.AfterTestClassStartingAsync() in xunit.execution.dotnet.dll:token 0x600015c+0x23
   at Xunit.Sdk.TestClassRunner`1.RunAsync() in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\Runners\TestClassRunner.cs:line 170
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine) in System.Private.CoreLib.dll:token 0x6004ee8+0x28
   at Xunit.Sdk.TestClassRunner`1.RunAsync() in xunit.execution.dotnet.dll:token 0x60000d4+0x23
   at Xunit.Sdk.XunitTestCollectionRunner.RunTestClassAsync(ITestClass testClass, IReflectionTypeInfo class, IEnumerable`1 testCases) in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\Runners\XunitTestCollectionRunner.cs:line 158
   at Xunit.Sdk.TestCollectionRunner`1.RunTestClassesAsync() in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\Runners\TestCollectionRunner.cs:line 130
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine) in System.Private.CoreLib.dll:token 0x6004ee8+0x28
   at Xunit.Sdk.TestCollectionRunner`1.RunTestClassesAsync() in xunit.execution.dotnet.dll:token 0x60000e9+0x23
   at Xunit.Sdk.TestCollectionRunner`1.RunAsync() in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\Runners\TestCollectionRunner.cs:line 101
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine) in System.Private.CoreLib.dll:token 0x6004ee8+0x28
   at Xunit.Sdk.TestCollectionRunner`1.RunAsync() in xunit.execution.dotnet.dll:token 0x60000e8+0x23
   at Xunit.Sdk.XunitTestAssemblyRunner.RunTestCollectionAsync(IMessageBus messageBus, ITestCollection testCollection, IEnumerable`1 testCases, CancellationTokenSource cancellationTokenSource) in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\Runners\XunitTestAssemblyRunner.cs:line 235
   at Xunit.Sdk.XunitTestAssemblyRunner.<>c__DisplayClass14_2.<RunTestCollectionsAsync>b__2() in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\Runners\XunitTestAssemblyRunner.cs:line 184
   at System.Threading.Tasks.Task`1.InnerInvoke() in System.Private.CoreLib.dll:token 0x600317f+0xf
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state) in System.Private.CoreLib.dll:token 0x6002eaa+0x40
   at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot, Thread threadPoolThread) in System.Private.CoreLib.dll:token 0x600327a+0x96
   at System.Threading.Tasks.Task.ExecuteEntry() in System.Private.CoreLib.dll:token 0x6003276+0x36
   at System.Threading.Tasks.SynchronizationContextTaskScheduler.<>c.<.cctor>b__8_0(Object s) in System.Private.CoreLib.dll:token 0x600342d+0x0
   at Xunit.Sdk.MaxConcurrencySyncContext.RunOnSyncContext(SendOrPostCallback callback, Object state) in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\MaxConcurrencySyncContext.cs:line 106
   at Xunit.Sdk.MaxConcurrencySyncContext.<>c__DisplayClass11_0.<WorkerThreadProc>b__0(Object _) in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\MaxConcurrencySyncContext.cs:line 96
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state) in System.Private.CoreLib.dll:token 0x6002eaa+0x40
   at Xunit.Sdk.MaxConcurrencySyncContext.WorkerThreadProc() in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\MaxConcurrencySyncContext.cs:line 96
   at Xunit.Sdk.XunitWorkerThread.<>c.<QueueUserWorkItem>b__5_0(Object _) in C:\Dev\xunit\xunit\src\common\XunitWorkerThread.cs:line 37
   at System.Threading.Tasks.Task.InnerInvoke() in System.Private.CoreLib.dll:token 0x600327b+0x25
   at System.Threading.Tasks.Task.<>c.<.cctor>b__271_0(Object obj) in System.Private.CoreLib.dll:token 0x6003320+0x0
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state) in System.Private.CoreLib.dll:token 0x6002eaa+0x40
   at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot, Thread threadPoolThread) in System.Private.CoreLib.dll:token 0x600327a+0x96
   at System.Threading.Tasks.Task.ExecuteEntryUnsafe(Thread threadPoolThread) in System.Private.CoreLib.dll:token 0x6003278+0x2b
   at System.Threading.Tasks.ThreadPoolTaskScheduler.<>c.<.cctor>b__10_0(Object s) in System.Private.CoreLib.dll:token 0x600344a+0x0
   at System.Threading.Thread.StartCallback() in System.Private.CoreLib.dll:token 0x6002c8e+0xe
    Microsoft.EntityFrameworkCore.Query.GearsOfWarQuerySqliteTest.Where_TimeSpan_Seconds [SKIP]
      Issue#18844
=== COMMAND LINE ===
"C:\dotnet\efcore\.dotnet\dotnet.exe" exec --depsfile "C:\dotnet\efcore\artifacts\bin\EFCore.Sqlite.FunctionalTests\Debug\net6.0\Microsoft.EntityFrameworkCore.Sqlite.FunctionalTests.deps.json" --runtimeconfig "C:\dotnet\efcore\artifacts\bin\EFCore.Sqlite.FunctionalTests\Debug\net6.0\Microsoft.EntityFrameworkCore.Sqlite.FunctionalTests.runtimeconfig.json"  "C:\Users\ajcvi\.nuget\packages\xunit.runner.console/2.4.1/tools/netcoreapp2.0/xunit.console.dll" "C:\dotnet\efcore\artifacts\bin\EFCore.Sqlite.FunctionalTests\Debug\net6.0\Microsoft.EntityFrameworkCore.Sqlite.FunctionalTests.dll" -noautoreporters -xml "C:\dotnet\efcore\artifacts\TestResults\Debug\EFCore.Sqlite.FunctionalTests_net6.0_x64.xml" -html "C:\dotnet\efcore\artifacts\TestResults\Debug\EFCore.Sqlite.FunctionalTests_net6.0_x64.html"  > "C:\dotnet\efcore\artifacts\log\Debug\EFCore.Sqlite.FunctionalTests_net6.0_x64.log" 2>&1
@ajcvickers
Copy link
Member Author

/cc @bricelam

Could this be due to concurrency issue when using ClearAllPools? If so, we could revert that change for 6.0.

@bricelam
Copy link
Contributor

bricelam commented Sep 14, 2021

Hmm, could have been made worse by it, but still probably a legitimate concurrency issue.

@ajcvickers
Copy link
Member Author

I've done a few builds today and only seen it happen once.

@ajcvickers
Copy link
Member Author

Has now failed twice more. Overall seems to be failing about 1 in 3 times.

@ajcvickers
Copy link
Member Author

ajcvickers commented Sep 16, 2021

Reverted #25797 to get tests running reliably again.

@bricelam bricelam modified the milestones: 6.0.0, Backlog Sep 24, 2021
@ajcvickers ajcvickers modified the milestones: Backlog, 7.0.0 Oct 27, 2021
@ajcvickers ajcvickers added punted-for-7.0 Originally planned for the EF Core 7.0 (EF7) release, but moved out due to resource constraints. and removed propose-punt labels Jul 7, 2022
@ajcvickers ajcvickers modified the milestones: 7.0.0, Backlog Jul 7, 2022
@bricelam bricelam removed their assignment Jul 8, 2023
@ajcvickers ajcvickers modified the milestones: Backlog, 9.0.0 Dec 14, 2023
@ajcvickers ajcvickers self-assigned this Dec 14, 2023
@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 Dec 14, 2023
ajcvickers added a commit that referenced this issue Dec 14, 2023
Fixes #25797
Fixes #26016

I identified two race conditions, both caused by splitting state across multiple data structures. In particular, the Semaphore and the two ConcurrentStacks must stay in sync--that is, the Semaphore can let someone get a collection if and only if there is a connection available in the one of the stacks.

The fix is to wrap all these things in a single lock. It's possible that we don't need a full lock, but we already have one to protect _collections which can easily be expanded to cover the right areas.

Once this lock is used, the semaphore is no longer needed, and the stacks don't need to be concurrent because they are protected by the lock.
ajcvickers added a commit that referenced this issue Dec 14, 2023
Fixes #25797
Fixes #26016

I identified two race conditions, both caused by splitting state across multiple data structures. In particular, the Semaphore and the two ConcurrentStacks must stay in sync--that is, the Semaphore can let someone get a collection if and only if there is a connection available in the one of the stacks.

The fix is to wrap all these things in a single lock. It's possible that we don't need a full lock, but we already have one to protect _collections which can easily be expanded to cover the right areas.

Once this lock is used, the semaphore is no longer needed, and the stacks don't need to be concurrent because they are protected by the lock.
@ajcvickers ajcvickers modified the milestones: 9.0.0, 9.0.0-preview1 Jan 31, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area-adonet-sqlite area-groupby closed-fixed The issue has been fixed and is/will be included in the release indicated by the issue milestone. punted-for-6.0 punted-for-7.0 Originally planned for the EF Core 7.0 (EF7) release, but moved out due to resource constraints. type-bug
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants