hung at connection.open

[omhappy]

I have an app in Azure AKS container. When the app call connection.open to connect to Azure Sql, it hung at ReadInternal method of class SslOverTdsStream occasionally.
We create a dump and find that the ReadInternal method doesn't check the return value of _stream.Read.
if the socket is closed, the return value is 0, then the method will be an infinite loop.

[stephentoub]

@omhappy, what version of .NET are you using?

I do see code you're referring to like:
https://github.com/dotnet/corefx/blob/d3911035f2ba3eb5c44310342cc1d654e42aa316/src/System.Data.SqlClient/src/System/Data/SqlClient/SNI/SslOverTdsStream.cs#L114-L120
in the latest version.

[Wraith2]

It's in the latest System version so it's likely to be the same in the Microsoft version. It should probably check for 0 on the read and then bail out for the caller to handle the incomplete packet.

/cc @cheenamalhotra @David-Engel

[omhappy]

I use .Net Core 2.1 the code is
https://github.com/dotnet/corefx/blob/release/2.1/src/System.Data.SqlClient/src/System/Data/SqlClient/SNI/SslOverTdsStream.cs

[cheenamalhotra]

Closed in error.

[oldzhu]

This issue occurred frequently in one of our customer environment. when the issue occurs, we could see the high CPU utilization of the thread which call stack is like the below:

(lldb) clrstack
OS Thread Id: 0x73f8 (39)
Child SP IP Call Site
00007F918B1A53D0 00007f9516af53c7 [InlinedCallFrame: 00007f918b1a53d0] Interop+Sys.ReceiveMessage(System.Runtime.InteropServices.SafeHandle, MessageHeader*, System.Net.Sockets.SocketFlags, Int64*)
00007F918B1A53D0 00007f949f6df19b [InlinedCallFrame: 00007f918b1a53d0] Interop+Sys.ReceiveMessage(System.Runtime.InteropServices.SafeHandle, MessageHeader*, System.Net.Sockets.SocketFlags, Int64*)
00007F918B1A53C0 00007F949F6DF19B ILStubClass.IL_STUB_PInvoke(System.Runtime.InteropServices.SafeHandle, MessageHeader*, System.Net.Sockets.SocketFlags, Int64*)
00007F918B1A5460 00007F94A0782568 System.Net.Sockets.SocketPal.Receive(System.Net.Sockets.SafeSocketHandle, System.Net.Sockets.SocketFlags, System.Span1<Byte>, Byte[], Int32 ByRef, System.Net.Sockets.SocketFlags ByRef, Error ByRef) 00007F918B1A5510 00007F94A07823B1 System.Net.Sockets.SocketPal.TryCompleteReceiveFrom(System.Net.Sockets.SafeSocketHandle, System.Span1, System.Collections.Generic.IList1<System.ArraySegment1>, System.Net.Sockets.SocketFlags, Byte[], Int32 ByRef, Int32 ByRef, System.Net.Sockets.SocketFlags ByRef, System.Net.Sockets.SocketError ByRef)
00007F918B1A5570 00007F94A0786DC1 System.Net.Sockets.SocketAsyncContext.ReceiveFrom(System.Memory1<Byte>, System.Net.Sockets.SocketFlags ByRef, Byte[], Int32 ByRef, Int32, Int32 ByRef) 00007F918B1A5610 00007F94A0786BCD System.Net.Sockets.SocketPal.Receive(System.Net.Sockets.SafeSocketHandle, Byte[], Int32, Int32, System.Net.Sockets.SocketFlags, Int32 ByRef) 00007F918B1A56B0 00007F94A07868D6 System.Net.Sockets.Socket.Receive(Byte[], Int32, Int32, System.Net.Sockets.SocketFlags, System.Net.Sockets.SocketError ByRef) 00007F918B1A5700 00007F94A07860E0 System.Net.Sockets.NetworkStream.Read(Byte[], Int32, Int32) 00007F918B1A5750 00007F94A01C8D89 System.Data.SqlClient.SNI.SslOverTdsStream+<ReadInternal>d__11.MoveNext() 00007F918B1A57E0 00007F94A0789FD4 System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.Data.SqlClient.SNI.SslOverTdsStream+<ReadInternal>d__11, System.Data.SqlClient]](<ReadInternal>d__11 ByRef) 00007F918B1A5820 00007F94A0789F0A System.Data.SqlClient.SNI.SslOverTdsStream.ReadInternal(Byte[], Int32, Int32, System.Threading.CancellationToken, Boolean) 00007F918B1A5890 00007F94A0789E63 System.Data.SqlClient.SNI.SslOverTdsStream.Read(Byte[], Int32, Int32) 00007F918B1A58B0 00007F94A0795433 System.Net.FixedSizeReader.ReadPacket(System.IO.Stream, Byte[], Int32, Int32) 00007F918B1A58F0 00007F94A0793864 System.Net.Security.SslStream.StartReceiveBlob(Byte[], System.Net.AsyncProtocolRequest) 00007F918B1A5920 00007F94A078DE6C System.Net.Security.SslStream.CheckCompletionBeforeNextReceive(System.Net.Security.ProtocolToken, System.Net.AsyncProtocolRequest) 00007F918B1A5960 00007F94A078CD56 System.Net.Security.SslStream.StartSendBlob(Byte[], Int32, System.Net.AsyncProtocolRequest) 00007F918B1A5990 00007F94A07933A0 System.Net.Security.SslStream.ProcessReceivedBlob(Byte[], Int32, System.Net.AsyncProtocolRequest) 00007F918B1A59F0 00007F94A07938BB System.Net.Security.SslStream.StartReceiveBlob(Byte[], System.Net.AsyncProtocolRequest) 00007F918B1A5A20 00007F94A078DE6C System.Net.Security.SslStream.CheckCompletionBeforeNextReceive(System.Net.Security.ProtocolToken, System.Net.AsyncProtocolRequest) 00007F918B1A5A60 00007F94A078CD56 System.Net.Security.SslStream.StartSendBlob(Byte[], Int32, System.Net.AsyncProtocolRequest) 00007F918B1A5A90 00007F94A07D2460 System.Net.Security.SslStream.ForceAuthentication(Boolean, Byte[], System.Net.AsyncProtocolRequest) 00007F918B1A5AD0 00007F94A07D215A System.Net.Security.SslStream.ProcessAuthentication(System.Net.LazyAsyncResult, System.Threading.CancellationToken) 00007F918B1A5B50 00007F94A07ED8F6 System.Net.Security.SslStream.AuthenticateAsClient(System.Net.Security.SslClientAuthenticationOptions) 00007F918B1A5B70 00007F94A07ED70C System.Data.SqlClient.SNI.SNITCPHandle.EnableSsl(UInt32) 00007F918B1A5BA0 00007F94A07ED665 System.Data.SqlClient.SNI.SNIProxy.EnableSsl(System.Data.SqlClient.SNI.SNIHandle, UInt32) 00007F918B1A5BD0 00007F94A01C5ED2 System.Data.SqlClient.TdsParser.ConsumePreLoginHandshake(Boolean, Boolean, Boolean, Boolean ByRef, Boolean ByRef) 00007F918B1A5CA0 00007F94A08073B0 System.Data.SqlClient.TdsParser.Connect(System.Data.SqlClient.ServerInfo, System.Data.SqlClient.SqlInternalConnectionTds, Boolean, Int64, Boolean, Boolean, Boolean, Boolean) 00007F918B1A5D30 00007F94A0806ED6 System.Data.SqlClient.SqlInternalConnectionTds.AttemptOneLogin(System.Data.SqlClient.ServerInfo, System.String, System.Security.SecureString, Boolean, System.Data.ProviderBase.TimeoutTimer, Boolean) 00007F918B1A5D80 00007F94A01BCC3C System.Data.SqlClient.SqlInternalConnectionTds.LoginNoFailover(System.Data.SqlClient.ServerInfo, System.String, System.Security.SecureString, Boolean, System.Data.SqlClient.SqlConnectionString, System.Data.SqlClient.SqlCredential, System.Data.ProviderBase.TimeoutTimer) 00007F918B1A5EA0 00007F94A0846E12 System.Data.SqlClient.SqlInternalConnectionTds.OpenLoginEnlist(System.Data.ProviderBase.TimeoutTimer, System.Data.SqlClient.SqlConnectionString, System.Data.SqlClient.SqlCredential, System.String, System.Security.SecureString, Boolean) 00007F918B1A5F30 00007F94A01BBD13 System.Data.SqlClient.SqlInternalConnectionTds..ctor(System.Data.ProviderBase.DbConnectionPoolIdentity, System.Data.SqlClient.SqlConnectionString, System.Data.SqlClient.SqlCredential, System.Object, System.String, System.Security.SecureString, Boolean, System.Data.SqlClient.SqlConnectionString, System.Data.SqlClient.SessionData, Boolean, System.String) 00007F918B1A5FB0 00007F94A08468D0 System.Data.SqlClient.SqlConnectionFactory.CreateConnection(System.Data.Common.DbConnectionOptions, System.Data.Common.DbConnectionPoolKey, System.Object, System.Data.ProviderBase.DbConnectionPool, System.Data.Common.DbConnection, System.Data.Common.DbConnectionOptions) 00007F918B1A6070 00007F94A0846468 System.Data.ProviderBase.DbConnectionFactory.CreatePooledConnection(System.Data.ProviderBase.DbConnectionPool, System.Data.Common.DbConnection, System.Data.Common.DbConnectionOptions, System.Data.Common.DbConnectionPoolKey, System.Data.Common.DbConnectionOptions) 00007F918B1A60A0 00007F94A08460D6 System.Data.ProviderBase.DbConnectionPool.CreateObject(System.Data.Common.DbConnection, System.Data.Common.DbConnectionOptions, System.Data.ProviderBase.DbConnectionInternal) 00007F918B1A6100 00007F94A084600D System.Data.ProviderBase.DbConnectionPool.UserCreateRequest(System.Data.Common.DbConnection, System.Data.Common.DbConnectionOptions, System.Data.ProviderBase.DbConnectionInternal) 00007F918B1A6140 00007F94A01B9B9B System.Data.ProviderBase.DbConnectionPool.TryGetConnection(System.Data.Common.DbConnection, UInt32, Boolean, Boolean, System.Data.Common.DbConnectionOptions, System.Data.ProviderBase.DbConnectionInternal ByRef) 00007F918B1A61D0 00007F94A07FB11D System.Data.ProviderBase.DbConnectionPool.TryGetConnection(System.Data.Common.DbConnection, System.Threading.Tasks.TaskCompletionSource1<System.Data.ProviderBase.DbConnectionInternal>, System.Data.Common.DbConnectionOptions, System.Data.ProviderBase.DbConnectionInternal ByRef)
00007F918B1A6220 00007F94A01B79C4 System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(System.Data.Common.DbConnection, System.Threading.Tasks.TaskCompletionSource1<System.Data.ProviderBase.DbConnectionInternal>, System.Data.Common.DbConnectionOptions, System.Data.ProviderBase.DbConnectionInternal, System.Data.ProviderBase.DbConnectionInternal ByRef) 00007F918B1A6290 00007F94A07FAB2B System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(System.Data.Common.DbConnection, System.Data.ProviderBase.DbConnectionFactory, System.Threading.Tasks.TaskCompletionSource1<System.Data.ProviderBase.DbConnectionInternal>, System.Data.Common.DbConnectionOptions)
00007F918B1A62E0 00007F94A07FA960 System.Data.SqlClient.SqlConnection.TryOpen(System.Threading.Tasks.TaskCompletionSource`1<System.Data.ProviderBase.DbConnectionInternal>)
00007F918B1A6310 00007F94A07FA4B9 System.Data.SqlClient.SqlConnection.Open()
...

(lldb) dumpobj 00007f91f29ebee8
Name: System.Data.SqlClient.SNI.SslOverTdsStream
MethodTable: 00007f94a059edf0
EEClass: 00007f94a06a1008
Size: 48(0x30) bytes
File: /app/runtimes/unix/lib/netcoreapp2.1/System.Data.SqlClient.dll
Fields:
MT Field Offset Type VT Attr Value Name
0000000000000000 4001318 8 ...eam+ReadWriteTask 0 instance 0000000000000000 _activeReadWriteTask
00007f949cf09d70 4001319 10 ...ing.SemaphoreSlim 0 instance 0000000000000000 _asyncActiveSemaphore
00007f949cf04ef8 4001317 1140 System.IO.Stream 0 static 00007f94740835a8 Null
00007f949cf04ef8 400078a 18 System.IO.Stream 0 instance 00007f91f29ebeb0 _stream
00007f949c8aa0e8 400078b 20 System.Int32 1 instance 0 _packetBytes
00007f949c8a60c8 400078c 24 System.Boolean 1 instance 1 _encapsulate

we could see for the SslOverTdsStream instance which _encapsulate is 1, so it is very obvious thread went into endless loop as the below code when readBytes always returns zero ( the customer said it will return zero always when connection disconnected)

  private async Task<int> ReadInternalEncapsulate(byte[] buffer, int offset, int count, CancellationToken token, bool async)

...
while (readBytes < TdsEnums.HEADER_LEN)
{
readBytes += (async ?
await ReadInternalAsync(packetData, readBytes, TdsEnums.HEADER_LEN - readBytes, token).ConfigureAwait(false) :
ReadInternalSync(packetData, readBytes, TdsEnums.HEADER_LEN - readBytes)
);
}
...

Could fix it by breaking the loop when the readbytes returns zero? It has been opened for a long time and when the issue can get fixed? Any ETA?

[cheenamalhotra]

Fixed with #577 - closing.