dotnet / SqlClient

Microsoft.Data.SqlClient provides database connectivity to SQL Server for .NET applications.
MIT License
847 stars 282 forks source link

Microsoft.Data.SqlClient InvalidOperationException 2 simultaneous calls to Open to remote host #2025

Open rrs opened 1 year ago

rrs commented 1 year ago

Bug

When attempting to connect to a remote host that is not available for some specific reasons, and when opening multiple concurrent connections (2 is enough), sometimes an InvalidOperationException is thrown with the suggestion the connection pool is exhausted.

Exception message: Timeout expired.  The timeout period elapsed prior to obtaining a connection from the pool.  This may have occurred because all pooled connections were in use and max pool size was reached.
Stack trace: at Microsoft.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at Microsoft.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at Microsoft.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry, SqlConnectionOverrides overrides)
   at Microsoft.Data.SqlClient.SqlConnection.Open(SqlConnectionOverrides overrides)
   at Program.<<Main>$>g__Query|0_0() in E:\Source\Uncontrolled\MicrosoftSqlClientInvalidOperationException\MicrosoftSqlClientInvalidOperationException\Program.cs:line 24
   at System.Threading.Tasks.Task`1.InnerInvoke()
   at System.Threading.Tasks.Task.<>c.<.cctor>b__272_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>$>d__0.MoveNext() in E:\Source\Uncontrolled\MicrosoftSqlClientInvalidOperationException\MicrosoftSqlClientInvalidOperationException\Program.cs:line 13

Reproduce

https://github.com/rrs/MicrosoftSqlClientInvalidOperationException

Point to another machine on your network where you can block it, using a firewall rule to block SQL on that port. It will not throw the exception every time. Sometimes you get the 'real' exception which in my case is Access Denied as you would expect. You can change the two tasks to call the QueryAsync (which calls openasync) and change to one of each. This is where it gets a bit hairy. I find on my machine if I do

var t1 = Task.Run(Query); 
var t2 = Task.Run(Query);

it will often InvalidOperationException. If I do

var t1 = Task.Run(QueryAsync); 
var t2 = Task.Run(Query);

it will often InvalidOperationException. If I do

var t1 = Task.Run(Query); 
var t2 = Task.Run(QueryAsync);

it won't do it at all or if i do

var t1 = Task.Run(QueryAsync); 
var t2 = Task.Run(QueryAsync);

It won't do it at all However in our (nearly) production code which uses just the OpenAsync method it has been caught doing it but just once in quite few weeks of testing.

Expected behavior

The exception should be one of the underlying Microsoft.Data.SqlClient.SqlException that you can see are thrown, or the message should express what is actually going wrong.

Further technical details

Microsoft.Data.SqlClient version: Nuget version 5.1.1 .NET target: .Net 6 SQL Server version: Any Operating system: Windows 11

Additional context

Certain types of connectivity seem to be required to trigger this. We have had this when pulling a network cable and it is most easily reproducible by setting a blocking rule on the sql port on the remote host. (Outbound might work too)

A little bit more background to give some context. We have added some connection durability code to our app that will popup a spinner and say there is a problem, and will keep retrying the operation as long as the exception code is connection based errors. This works very well and in most scenarios is robust. However there are some cases where it throws this exception, seemingly about connection pooling. However as shown in the example project this can be triggered with just 2 simultaneous connections.

The exception I get when it's not an invalid operation exception

Microsoft.Data.SqlClient.SqlException (0x80131904): A network-related or instance-specific error occurred while establishing a connection to SQL Server. The server was not found or was not accessible. Verify that the instance name is correct and that SQL Server is configured to allow remote connections. (provider: Named Pipes Provider, error: 40 - Could not open a connection to SQL Server)
 ---> System.ComponentModel.Win32Exception (5): Access is denied.
   at Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
   at Microsoft.Data.SqlClient.TdsParser.Connect(ServerInfo serverInfo, SqlInternalConnectionTds connHandler, Boolean ignoreSniOpenTimeout, Int64 timerExpire, SqlConnectionString connectionOptions, Boolean withFailover)
   at Microsoft.Data.SqlClient.SqlInternalConnectionTds.AttemptOneLogin(ServerInfo serverInfo, String newPassword, SecureString newSecurePassword, Boolean ignoreSniOpenTimeout, TimeoutTimer timeout, Boolean withFailover)
   at Microsoft.Data.SqlClient.SqlInternalConnectionTds.LoginNoFailover(ServerInfo serverInfo, String newPassword, SecureString newSecurePassword, Boolean redirectedUserInstance, SqlConnectionString connectionOptions, SqlCredential credential, TimeoutTimer timeout)
   at Microsoft.Data.SqlClient.SqlInternalConnectionTds.OpenLoginEnlist(TimeoutTimer timeout, SqlConnectionString connectionOptions, SqlCredential credential, String newPassword, SecureString newSecurePassword, Boolean redirectedUserInstance)
   at Microsoft.Data.SqlClient.SqlInternalConnectionTds..ctor(DbConnectionPoolIdentity identity, SqlConnectionString connectionOptions, SqlCredential credential, Object providerInfo, String newPassword, SecureString newSecurePassword, Boolean redirectedUserInstance, SqlConnectionString userConnectionOptions, SessionData reconnectSessionData, Boolean applyTransientFaultHandling, String accessToken, DbConnectionPool pool)
   at Microsoft.Data.SqlClient.SqlConnectionFactory.CreateConnection(DbConnectionOptions options, DbConnectionPoolKey poolKey, Object poolGroupProviderInfo, DbConnectionPool pool, DbConnection owningConnection, DbConnectionOptions userOptions)
   at Microsoft.Data.ProviderBase.DbConnectionFactory.CreatePooledConnection(DbConnectionPool pool, DbConnection owningObject, DbConnectionOptions options, DbConnectionPoolKey poolKey, DbConnectionOptions userOptions)
   at Microsoft.Data.ProviderBase.DbConnectionPool.CreateObject(DbConnection owningObject, DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
   at Microsoft.Data.ProviderBase.DbConnectionPool.UserCreateRequest(DbConnection owningObject, DbConnectionOptions userOptions, DbConnectionInternal oldConnection)
   at Microsoft.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at Microsoft.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at Microsoft.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at Microsoft.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at Microsoft.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry, SqlConnectionOverrides overrides)
   at Microsoft.Data.SqlClient.SqlConnection.Open(SqlConnectionOverrides overrides)
   at Program.<<Main>$>g__Query|0_0() in E:\Source\Uncontrolled\MicrosoftSqlClientInvalidOperationException\MicrosoftSqlClientInvalidOperationException\Program.cs:line 24
   at System.Threading.Tasks.Task`1.InnerInvoke()
   at System.Threading.Tasks.Task.<>c.<.cctor>b__272_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 E:\Source\Uncontrolled\MicrosoftSqlClientInvalidOperationException\MicrosoftSqlClientInvalidOperationException\Program.cs:line 13
ClientConnectionId:00000000-0000-0000-0000-000000000000
Error Number:5,State:0,Class:20
JRahnama commented 1 year ago

@rrs thanks for bringing this up. We will investigate this.

DavoudEshtehari commented 1 year ago

I confirm the issue is reproducible with the repro app. The connection pool is single-threaded by design, and a semaphore manages the queue. A possible scenario would be a minor gap that causes a connection enters the pooling queue, while it's about to timeout and the other connection is still waiting for a response from the server. If a task with the timeout owned the main thread it could throw it unless the other task throws the SqlException.

Adding the snapshots for the record: image

image