Sqlclient: Deadlock in System.Data.SqlClient reproduced only on Unix

Created on 6 Nov 2018  路  6Comments  路  Source: dotnet/SqlClient

Hi !

We hit a deadlock in System.Data.SqlClient (4.5.1) when running on Unix.
The deadlock is random but we run into it quite often, we don't reproduce on windows.

Thanks to the work done for https://github.com/dotnet/coreclr/issues/20803 we were able to use the command syncblk on my unix memory dump.

It looks like OnTimeout (https://github.com/dotnet/corefx/blob/master/src/System.Data.SqlClient/src/System/Data/SqlClient/TdsParserStateObject.cs#L2166)
kicks-in in the middle of ExecuteSqlBatch ( https://github.com/dotnet/corefx/blob/master/src/System.Data.SqlClient/src/System/Data/SqlClient/TdsParser.cs#L6934 and
https://github.com/dotnet/corefx/blob/master/src/System.Data.SqlClient/src/System/Data/SqlClient/TdsParser.cs#L7018)

Unfortunately we're not sure what approach to take regarding this deadlock, any help would be welcome !

Cheers


Here are some info we gathered that might be of help.
Let me know if more is needed.

(lldb) syncblk
Index SyncBlock MonitorHeld Recursion Owning Thread Info  SyncBlock Owner
 1672 00007F8B94008FA8            3         1 00007F8BB401F1F0 982e  89   00007f8db9bfc2f0 System.Threading.SemaphoreSlim
 1677 00007F8B940090E8            3         1 00007F8B8801CFC0 982b  88   00007f8db9bfce48 System.Data.SqlClient.SNI.TdsParserStateObjectManaged
-----------------------------
Total           12505
Free            10107


(lldb) clrstack
OS Thread Id: 0x982b (88)
        Child SP               IP Call Site
00007F8BEFFFE4E0 00007f9479c2e945 [GCFrame: 00007f8befffe4e0]
00007F8BEFFFE5D0 00007f9479c2e945 [GCFrame: 00007f8befffe5d0]
00007F8BEFFFE630 00007f9479c2e945 [HelperMethodFrame_1OBJ: 00007f8befffe630] System.Threading.Monitor.Enter(System.Object)
00007F8BEFFFE780 00007F9402631032 System.Data.SqlClient.SqlInternalConnectionTds+SyncAsyncLock.Wait(Boolean)
00007F8BEFFFE7B0 00007F9404825455 System.Data.SqlClient.TdsParserStateObject.SendAttention(Boolean)
00007F8BEFFFE810 00007F94048241A5 System.Data.SqlClient.TdsParserStateObject.OnTimeout(System.Object)
00007F8BEFFFE870 00007F93FECB6596 System.Threading.TimerQueueTimer.CallCallback()
00007F8BEFFFE8B0 00007F93FECB63BE System.Threading.TimerQueueTimer.Fire()
00007F8BEFFFE900 00007F93FECE7B5B System.Threading.TimerQueue.FireNextTimers()
00007F8BEFFFECB0 00007f947835bfff [DebuggerU2MCatchHandlerFrame: 00007f8befffecb0]

(lldb) clrstack -a
OS Thread Id: 0x982b (88)
        Child SP               IP Call Site
00007F8BEFFFE4E0 00007f9479c2e945 [GCFrame: 00007f8befffe4e0]
00007F8BEFFFE5D0 00007f9479c2e945 [GCFrame: 00007f8befffe5d0]
00007F8BEFFFE630 00007f9479c2e945 [HelperMethodFrame_1OBJ: 00007f8befffe630] System.Threading.Monitor.Enter(System.Object)
00007F8BEFFFE780 00007F9402631032 System.Data.SqlClient.SqlInternalConnectionTds+SyncAsyncLock.Wait(Boolean)
    PARAMETERS:
        this (<CLR reg>) = 0x00007f8db9bfc2d8
        canReleaseFromAnyThread (<CLR reg>) = 0x0000000000000000

00007F8BEFFFE7B0 00007F9404825455 System.Data.SqlClient.TdsParserStateObject.SendAttention(Boolean)
    PARAMETERS:
        this (0x00007F8BEFFFE7C8) = 0x00007f8db9bfce48
        mustTakeWriteLock = <no data>
    LOCALS:
        <CLR reg> = 0x00007f8cf9e2f208
        <no data>
        <no data>

00007F8BEFFFE810 00007F94048241A5 System.Data.SqlClient.TdsParserStateObject.OnTimeout(System.Object)
    PARAMETERS:
        this (0x00007F8BEFFFE828) = 0x00007f8db9bfce48
        state = <no data>
    LOCALS:
        <no data>
        <no data>
        0x00007F8BEFFFE820 = 0x00007f8cf9e2ebb0
        <no data>

00007F8BEFFFE870 00007F93FECB6596 System.Threading.TimerQueueTimer.CallCallback()
    PARAMETERS:
        this = <no data>
    LOCALS:
        <no data>

00007F8BEFFFE8B0 00007F93FECB63BE System.Threading.TimerQueueTimer.Fire()
    PARAMETERS:
        this (<CLR reg>) = 0x00007f8ecabc0830
    LOCALS:
        <no data>
        <no data>
        <no data>
        <no data>
        <no data>
        <no data>

00007F8BEFFFE900 00007F93FECE7B5B System.Threading.TimerQueue.FireNextTimers()
    PARAMETERS:
        this = <no data>
    LOCALS:
        <no data>
        <no data>
        <no data>
        <no data>
        <no data>
        <no data>
        <no data>
        <no data>
        <no data>
        <no data>
        <no data>

00007F8BEFFFECB0 00007f947835bfff [DebuggerU2MCatchHandlerFrame: 00007f8befffecb0]

(lldb) clrstack
OS Thread Id: 0x982e (89)
        Child SP               IP Call Site
00007F8BEE1F2080 00007f9479c2e945 [GCFrame: 00007f8bee1f2080]
00007F8BEE1F2170 00007f9479c2e945 [GCFrame: 00007f8bee1f2170]
00007F8BEE1F21D0 00007f9479c2e945 [HelperMethodFrame_1OBJ: 00007f8bee1f21d0] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)
00007F8BEE1F2320 00007F94029A90D7 System.Data.SqlClient.TdsParserStateObject.ExecuteFlush()
00007F8BEE1F2360 00007F94029A87EF System.Data.SqlClient.TdsParser.TdsExecuteSQLBatch(System.String, Int32, System.Data.Sql.SqlNotificationRequest, System.Data.SqlClient.TdsParserStateObject, Boolean, Boolean)
00007F8BEE1F23D0 00007F94029A778D System.Data.SqlClient.SqlCommand.RunExecuteNonQueryTds(System.String, Boolean, Int32, Boolean)
00007F8BEE1F2480 00007F94029A6A05 System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(System.Threading.Tasks.TaskCompletionSource`1<System.Object>, Boolean, Int32, Boolean, System.String)
00007F8BEE1F24F0 00007F94029A5DBC System.Data.SqlClient.SqlCommand.BeginExecuteNonQuery(System.AsyncCallback, System.Object)
00007F8BEE1F2560 00007F93FECBCC05 System.Threading.Tasks.TaskFactory`1[[System.Int32, System.Private.CoreLib]].FromAsyncImpl(System.Func`3<System.AsyncCallback,System.Object,System.IAsyncResult>, System.Func`2<System.IAsyncResult,Int32>, System.Action`1<System.IAsyncResult>, System.Object, System.Threading.Tasks.TaskCreationOptions)
00007F8BEE1F25B0 00007F94029A4CB0 System.Data.SqlClient.SqlCommand.ExecuteNonQueryAsync(System.Threading.CancellationToken)
00007F8BEE1F2660 00007F940262A868 Criteo.DevKit.DataAccess.Sql.DbContext+<CreateDbContextAsync>d__38.MoveNext() [C:\ps2\sdk\sdk-csharp\Criteo.DevKit\Criteo.DevKit\DataAccess\Sql\DbContext.cs @ 209]
00007F8BEE1F26D0 00007F93FEC1D62D System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
00007F8BEE1F2730 00007F94029A3EF1 System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[[System.__Canon, System.Private.CoreLib],[Criteo.DevKit.DataAccess.Sql.DbContext+<CreateDbContextAsync>d__38, Criteo.DevKit.netcore]].MoveNext()
00007F8BEE1F2760 00007F93FECE3352 System.Threading.Tasks.TaskSchedulerAwaitTaskContinuation+<>c.<Run>b__2_0(System.Object)
00007F8BEE1F2780 00007F93FEC5FD1A System.Threading.Tasks.Task.ExecuteWithThreadLocal(System.Threading.Tasks.Task ByRef)
00007F8BEE1F2810 00007F93FEC5FAF6 System.Threading.Tasks.Task.ExecuteEntry()
00007F8BEE1F2830 00007F94023A224C Sdk.Caching.Local.ReadOnlyCacheScheduler.<RunTask>b__19_0(System.Object) [C:\ps2\sdk\sdk-csharp\Sdk\Sdk.Caching\Local\ReadOnlyCacheScheduler.cs @ 302]
00007F8BEE1F2860 00007F93FEC1D62D System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
00007F8BEE1F28C0 00007F93FECAD328 System.Threading.ThreadPoolWorkQueue.Dispatch()
00007F8BEE1F2C90 00007f947835bfff [DebuggerU2MCatchHandlerFrame: 00007f8bee1f2c90]

(lldb) clrstack -a
OS Thread Id: 0x982e (89)
        Child SP               IP Call Site
00007F8BEE1F2080 00007f9479c2e945 [GCFrame: 00007f8bee1f2080]
00007F8BEE1F2170 00007f9479c2e945 [GCFrame: 00007f8bee1f2170]
00007F8BEE1F21D0 00007f9479c2e945 [HelperMethodFrame_1OBJ: 00007f8bee1f21d0] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)
00007F8BEE1F2320 00007F94029A90D7 System.Data.SqlClient.TdsParserStateObject.ExecuteFlush()
    PARAMETERS:
        this (0x00007F8BEE1F2330) = 0x00007f8db9bfce48
    LOCALS:
        <no data>
        <no data>
        <no data>
        <no data>

00007F8BEE1F2360 00007F94029A87EF System.Data.SqlClient.TdsParser.TdsExecuteSQLBatch(System.String, Int32, System.Data.Sql.SqlNotificationRequest, System.Data.SqlClient.TdsParserStateObject, Boolean, Boolean)
    PARAMETERS:
        this (0x00007F8BEE1F2380) = 0x00007f8db9bfcdb0
        text = <no data>
        timeout = <no data>
        notificationRequest = <no data>
        stateObj = <no data>
        sync = <no data>
        callerHasConnectionLock = <no data>
    LOCALS:
        0x00007F8BEE1F2378 = 0x00007f923a0a6868
        <no data>
        0x00007F8BEE1F2394 = 0x0000000000000001
        <no data>
        <no data>
        <no data>
        <no data>

00007F8BEE1F23D0 00007F94029A778D System.Data.SqlClient.SqlCommand.RunExecuteNonQueryTds(System.String, Boolean, Int32, Boolean)
    PARAMETERS:
        this (0x00007F8BEE1F2408) = 0x00007f923a0a62d0
        methodName = <no data>
        async = <no data>
        timeout = <no data>
        asyncWrite = <no data>
    LOCALS:
        0x00007F8BEE1F2400 = 0x00007f923a0a6840
        0x00007F8BEE1F2444 = 0x0000000000000001
        <no data>
        <no data>
        <no data>
        <no data>
        0x00007F8BEE1F23F8 = 0x0000000000000000
        <no data>
        <no data>
        <no data>

00007F8BEE1F2480 00007F94029A6A05 System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(System.Threading.Tasks.TaskCompletionSource`1<System.Object>, Boolean, Int32, Boolean, System.String)
    PARAMETERS:
        this = <no data>
        completion = <no data>
        sendToPipe = <no data>
        timeout = <no data>
        asyncWrite = <no data>
        methodName = <no data>
    LOCALS:
        <no data>
        <no data>
        <no data>
        <no data>

00007F8BEE1F24F0 00007F94029A5DBC System.Data.SqlClient.SqlCommand.BeginExecuteNonQuery(System.AsyncCallback, System.Object)
    PARAMETERS:
        this (0x00007F8BEE1F2518) = 0x00007f923a0a62d0
        callback = <no data>
        stateObject = <no data>
    LOCALS:
        <no data>
        0x00007F8BEE1F2510 = 0x0000000000000000
        <CLR reg> = 0x00007f923a0a67a8
        <no data>
        <no data>
        <no data>

00007F8BEE1F2560 00007F93FECBCC05 System.Threading.Tasks.TaskFactory`1[[System.Int32, System.Private.CoreLib]].FromAsyncImpl(System.Func`3<System.AsyncCallback,System.Object,System.IAsyncResult>, System.Func`2<System.IAsyncResult,Int32>, System.Action`1<System.IAsyncResult>, System.Object, System.Threading.Tasks.TaskCreationOptions)
    PARAMETERS:
        beginMethod = <no data>
        endFunction = <no data>
        endAction = <no data>
        state = <no data>
        creationOptions = <no data>
    LOCALS:
        0x00007F8BEE1F2570 = 0x00007f923a0a6698
        <no data>
        <no data>

00007F8BEE1F25B0 00007F94029A4CB0 System.Data.SqlClient.SqlCommand.ExecuteNonQueryAsync(System.Threading.CancellationToken)
    PARAMETERS:
        this (0x00007F8BEE1F25C0) = 0x00007f923a0a62d0
        cancellationToken = <no data>
    LOCALS:
        0x00007F8BEE1F25B8 = 0x00007f923a0a6418
        <no data>
        <no data>


(lldb) dumpobj 0x00007f8db9bfce48
Name:        System.Data.SqlClient.SNI.TdsParserStateObjectManaged
MethodTable: 00007f94027f7048
EEClass:     00007f9402804718
Size:        432(0x1b0) bytes
File:        .../runtimes/unix/lib/netstandard2.0/System.Data.SqlClient.dll
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00007f94027ef6a8  40006ac        8 ...lClient.TdsParser  0 instance 00007f8db9bfcdb0 _parser
00007f93fef80458  40006ad       10 System.WeakReference  0 instance 00007f8db9bfd0b8 _owner
00007f9402999a08  40006ae       18 ...eader+SharedState  0 instance 0000000000000000 _readerState
00007f93fef76a68  40006af      110         System.Int32  1 instance                0 _activateCount
00007f93fef76a68  40006b0      114         System.Int32  1 instance                8 _inputHeaderLen
00007f93fef76a68  40006b1      118         System.Int32  1 instance                8 _outputHeaderLen
00007f93fef5a970  40006b2       20        System.Byte[]  0 instance 00007f8db9c85390 _outBuff
00007f93fef76a68  40006b3      11c         System.Int32  1 instance              128 _outBytesUsed
00007f93fef5a970  40006b4       28        System.Byte[]  0 instance 00007f8dbc44d240 _inBuff
00007f93fef76a68  40006b5      120         System.Int32  1 instance              129 _inBytesUsed
00007f93fef76a68  40006b6      124         System.Int32  1 instance              129 _inBytesRead
00007f93fef76a68  40006b7      128         System.Int32  1 instance                0 _inBytesPacket
00007f93fef72198  40006b8      144          System.Byte  1 instance                1 _outputMessageType
00007f93fef72198  40006b9      145          System.Byte  1 instance                1 _messageStatus
00007f93fef72198  40006ba      146          System.Byte  1 instance                1 _outputPacketNumber
00007f93fef72020  40006bb      147       System.Boolean  1 instance                0 _pendingData
00007f93fef72020  40006bc      148       System.Boolean  1 instance                0 _fResetEventOwned
00007f93fef72020  40006bd      149       System.Boolean  1 instance                0 _fResetConnectionSent
00007f93fef72020  40006be      14a       System.Boolean  1 instance                0 _errorTokenReceived
00007f93fef72020  40006bf      14b       System.Boolean  1 instance                0 _bulkCopyOpperationInProgress
00007f93fef72020  40006c0      14c       System.Boolean  1 instance                0 _bulkCopyWriteTimeout
00007f93fef715e0  40006c1       30        System.Object  0 instance 00007f8db9bfd0d0 _writePacketLockObject
00007f93fef76a68  40006c2      12c         System.Int32  1 instance                1 _pendingCallbacks
00007f93fef76b98  40006c3       f0         System.Int64  1 instance 30000 _timeoutMilliseconds
00007f93fef76b98  40006c4       f8         System.Int64  1 instance 0 _timeoutTime
00007f93fef72020  40006c5      14d       System.Boolean  1 instance                0 _attentionSent
00007f93fef72020  40006c6      14e       System.Boolean  1 instance                0 _attentionReceived
00007f93fef72020  40006c7      14f       System.Boolean  1 instance                1 _attentionSending
00007f93fef72020  40006c8      150       System.Boolean  1 instance                1 _internalTimeout
00007f94027fad28  40006c9       38 ...lient.LastIOTimer  0 instance 00007f8db9c81cd8 _lastSuccessfulIOTimer
00007f9402524780  40006ca       40 ...ty.SecureString[]  0 instance 00007f8db9bfd0e8 _securePasswords
00007f93fef51430  40006cb       48       System.Int32[]  0 instance 00007f8db9bfd110 _securePasswordOffsetsInBuffer
00007f93fef72020  40006cc      151       System.Boolean  1 instance                0 _cancelled
00007f93fef80458  40006ce       50 System.WeakReference  0 instance 00007f8db9bfd130 _cancellationOwner
00007f93fef72020  40006cf      152       System.Boolean  1 instance                1 _hasOpenResult
00007f94029903e8  40006d0       58 ...ternalTransaction  0 instance 0000000000000000 _executedUnderTransaction
00007f93fef76c30  40006d1      100        System.UInt64  1 instance 0 _longlen
00007f93fef76c30  40006d2      108        System.UInt64  1 instance 0 _longlenleft
00007f93fef51430  40006d3       60       System.Int32[]  0 instance 0000000000000000 _decimalBits
00007f93fef5a970  40006d4       68        System.Byte[]  0 instance 00007f8db9bfd148 _bTmp
00007f93fef76a68  40006d5      130         System.Int32  1 instance                0 _bTmpRead
00007f93fef765b0  40006d6       70  System.Text.Decoder  0 instance 0000000000000000 _plpdecoder
00007f93fef72020  40006d7      153       System.Boolean  1 instance                0 _accumulateInfoEvents
00007f9402990580  40006d8       78 ....Data.SqlClient]]  0 instance 0000000000000000 _pendingInfoEvents
00007f93fef5a970  40006d9       80        System.Byte[]  0 instance 00007f8db9bfd170 _partialHeaderBuffer
00007f93fef76a68  40006da      134         System.Int32  1 instance                0 _partialHeaderBytesRead
00007f94027ea2a8  40006db       88 ...t._SqlMetaDataSet  0 instance 00007f8d3f368b60 _cleanupMetaData
00007f94029904f0  40006dc       90 ...DataSetCollection  0 instance 0000000000000000 _cleanupAltMetaDataSetArray
00007f93fef72020  40006dd      154       System.Boolean  1 instance                0 _receivedColMetaData
00007f94027f69f0  40006de      138         System.Int32  1 instance               10 _sniContext
00007f93fef72020  40006df      155       System.Boolean  1 instance                0 _bcpLock
00007f94027f6bd8  40006e0      160 ...Object+NullBitmap  1 instance 00007f8db9bfcfa8 _nullBitmapInfo
00007f94025232e8  40006e1       98 ...Private.CoreLib]]  0 instance 0000000000000000 _networkPacketTaskSource
00007f93fef80048  40006e2       a0 ...m.Threading.Timer  0 instance 00007f8ecabc0818 _networkPacketTimeout
00007f93fef72020  40006e3      156       System.Boolean  1 instance                1 _syncOverAsync
00007f93fef72020  40006e4      157       System.Boolean  1 instance                0 _snapshotReplay
00007f94027ff770  40006e5       a8 ...ect+StateSnapshot  0 instance 0000000000000000 _snapshot
00007f93fef76348  40006e6       b0 ....ExecutionContext  0 instance 0000000000000000 _executionContext
00007f93fef72020  40006e7      158       System.Boolean  1 instance                0 _asyncReadWithoutSnapshot
00007f94027e74e0  40006e8       b8 ...qlErrorCollection  0 instance 00007f8cf9e2f190 _errors
00007f94027e74e0  40006e9       c0 ...qlErrorCollection  0 instance 0000000000000000 _warnings
00007f93fef715e0  40006ea       c8        System.Object  0 instance 00007f8db9bfd190 _errorAndWarningsLock
00007f93fef72020  40006eb      159       System.Boolean  1 instance                1 _hasErrorOrWarning
00007f94027e74e0  40006ec       d0 ...qlErrorCollection  0 instance 0000000000000000 _preAttentionErrors
00007f94027e74e0  40006ed       d8 ...qlErrorCollection  0 instance 0000000000000000 _preAttentionWarnings
00007f94025232e8  40006ee       e0 ...Private.CoreLib]]  0 instance 00007f90b954ef50 _writeCompletionSource
00007f93fef76a68  40006ef      13c         System.Int32  1 instance                0 _asyncWriteCount
00007f93fef6f430  40006f0       e8     System.Exception  0 instance 0000000000000000 _delayedWriteAsyncCallbackException
00007f93fef76a68  40006f1      140         System.Int32  1 instance                0 _readingCount
00007f94047dfb28  400079a      170 ...SNIMarsConnection  0 instance 0000000000000000 _marsConnection
00007f94027fb6c0  400079b      178 ...ent.SNI.SNIHandle  0 instance 00007f8db9c81d60 _sessionHandle
00007f94027f99a8  400079c      180 ...ent.SNI.SNIPacket  0 instance 00007f8db9c87408 _sniPacket
00007f94027f99a8  400079d      188 ...ent.SNI.SNIPacket  0 instance 00007f8cf9e2f208 _sniAsyncAttnPacket
00007f94027f9ae0  400079e      190 ....Data.SqlClient]]  0 instance 00007f8db9bfcff8 _pendingWritePackets
00007f94027fa268  400079f      198 ...+WritePacketCache  0 instance 00007f8db9bfd048 _writePacketCache
00007f94027fa520  40007a0      1a0 ...ientContextStatus  0 instance 00007f8db9bfd090 sspiClientContextStatus

(lldb) dumpobj 00007f8db9bfcdb0
Name:        System.Data.SqlClient.TdsParser
MethodTable: 00007f94027ef6a8
EEClass:     00007f940274ecd0
Size:        152(0x98) bytes
File:        .../runtimes/unix/lib/netstandard2.0/System.Data.SqlClient.dll
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00007f94027f6c78  40005ec        8 ...ParserStateObject  0 instance 00007f8db9bfce48 _physicalStateObj
00007f94027f6c78  40005ed       10 ...ParserStateObject  0 instance 0000000000000000 _pMarsPhysicalConObj
00007f94027ef400  40005f0       70         System.Int32  1 instance                2 _state
00007f93fef6f820  40005f1       18        System.String  0 instance 00007f9138104ab8 _server
00007f93fef72020  40005f2       84       System.Boolean  1 instance                1 _fResetConnection
00007f93fef72020  40005f3       85       System.Boolean  1 instance                0 _fPreserveTransaction
00007f940292b3b0  40005f4       20 ...ient.SqlCollation  0 instance 00007f8db9c833d8 _defaultCollation
00007f93fef76a68  40005f5       74         System.Int32  1 instance             1252 _defaultCodePage
00007f93fef76a68  40005f6       78         System.Int32  1 instance             1033 _defaultLCID
00007f93fef71f48  40005f7       28 System.Text.Encoding  0 instance 00007f90380476e8 _defaultEncoding
00007f94027ef550  40005f9       7c         System.Int32  1 instance                0 _encryptionOption
00007f94029903e8  40005fa       30 ...ternalTransaction  0 instance 0000000000000000 _currentTransaction
00007f94029903e8  40005fb       38 ...ternalTransaction  0 instance 0000000000000000 _pendingTransaction
00007f93fef76b98  40005fc       68         System.Int64  1 instance 0 _retainedTransactionId
00007f93fef76a68  40005fd       80         System.Int32  1 instance                1 _nonTransactedOpenResultCount
00007f94027e7230  40005fe       40 ...rnalConnectionTds  0 instance 00007f8db9bfc1a0 _connHandler
00007f93fef72020  40005ff       86       System.Boolean  1 instance                0 _fMARS
00007f93fef72020  4000600       87       System.Boolean  1 instance                0 _loginWithFailover
00007f93fef8e8c8  4000601       48 ...ng.AutoResetEvent  0 instance 0000000000000000 _resetConnectionEvent
00007f94027fafe8  4000602       50 ...ParserSessionPool  0 instance 0000000000000000 _sessionPool
00007f93fef72020  4000603       88       System.Boolean  1 instance                1 _isYukon
00007f93fef72020  4000604       89       System.Boolean  1 instance                1 _isKatmai
00007f93fef72020  4000605       8a       System.Boolean  1 instance                1 _isDenali
00007f93fef5a970  4000606       58        System.Byte[]  0 instance 00007f8db9c82018 _sniSpnBuffer
00007f94027eb6c8  4000607       60 ...ent.SqlStatistics  0 instance 0000000000000000 _statistics
00007f93fef72020  4000608       8b       System.Boolean  1 instance                0 _statisticsIsInTransaction
00007f93fef72020  400060f       8c       System.Boolean  1 instance                0 _asyncWrite
00007f94027ef550  40005f8      240         System.Int32  1   static                0 s_sniSupportedEncryptionOption
00007f93fef5a970  4000609      430        System.Byte[]  0   static 00007f9038044908 s_nicAddress
00007f93fef76b00  400060a      244        System.UInt32  1   static                0 s_maxSSPILength
00007f93fef5a970  400060b      438        System.Byte[]  0   static 00007f91f8003dd8 s_longDataHeader
00007f93fef715e0  400060c      440        System.Object  0   static 00007f91f8003e10 s_tdsParserLock
00007f93fef5a970  400060d      448        System.Byte[]  0   static 00007f91f8003e28 s_xmlMetadataSubstituteSequence
00007f94027f8250  4000610      450 ....Data.SqlClient]]  0   static 00007f91f8003e48 s_tvpEmptyValue

(lldb) dumpobj 00007f8db9bfc1a0
Name:        System.Data.SqlClient.SqlInternalConnectionTds
MethodTable: 00007f94027e7230
EEClass:     00007f940274aa88
Size:        312(0x138) bytes
File:        .../runtimes/unix/lib/netstandard2.0/System.Data.SqlClient.dll
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00007f93fef72020  40000e5       38       System.Boolean  1 instance                0 _allowSetConnectionString
00007f93fef72020  40000e6       39       System.Boolean  1 instance                1 _hidePassword
00007f94027e0348  40000e7       30         System.Int32  1 instance                1 _state
00007f93fef80458  40000e8        8 System.WeakReference  0 instance 00007f8db9bfc348 _owningObject
00007f94027e2270  40000e9       10 ....DbConnectionPool  0 instance 00007f9138105368 _connectionPool
00007f9402997d08  40000ea       18 ...ferenceCollection  0 instance 00007f8db9c87448 _referenceCollection
00007f93fef76a68  40000eb       34         System.Int32  1 instance                0 _pooledCount
00007f93fef72020  40000ec       3a       System.Boolean  1 instance                0 _connectionIsDoomed
00007f93fef72020  40000ed       3b       System.Boolean  1 instance                0 _cannotBePooled
00007f93fef76778  40000ee       40      System.DateTime  1 instance 00007f8db9bfc1e0 _createTime
00007f93fef72020  40000ef       3c       System.Boolean  1 instance                0 _isInStasis
00007f94027ebd38  40000f0       20 ...tions.Transaction  0 instance 0000000000000000 _enlistedTransaction
00007f94027ebd38  40000f1       28 ...tions.Transaction  0 instance 0000000000000000 _enlistedTransactionOriginal
00007f9402993f50  40000e3       48 ...teChangeEventArgs  0   static 00007f8e77fff0f0 StateChangeClosed
00007f9402993f50  40000e4       50 ...teChangeEventArgs  0   static 00007f8e77fff108 StateChangeOpen
00007f94026efac0  400038d       48 ...lConnectionString  0 instance 00007f9138104998 _connectionOptions
00007f93fef72020  400038e       78       System.Boolean  1 instance                0 _isEnlistedInTransaction
00007f93fef5a970  400038f       50        System.Byte[]  0 instance 0000000000000000 _promotedDTCToken
00007f93fef5a970  4000390       58        System.Byte[]  0 instance 0000000000000000 _whereAbouts
00007f93fef72020  4000391       79       System.Boolean  1 instance                0 _isGlobalTransaction
00007f93fef72020  4000392       7a       System.Boolean  1 instance                0 _isGlobalTransactionEnabledForServer
00007f93fef6f820  4000394       60        System.String  0 instance 00007f8db9c833a0 <CurrentDatabase>k__BackingField
00007f93fef6f820  4000395       68        System.String  0 instance 00007f9138104ab8 <CurrentDataSource>k__BackingField
00007f9402bda7f0  4000396       70 ...egatedTransaction  0 instance 0000000000000000 <DelegatedTransaction>k__BackingField
00007f93fef778b0  4000393      3a0          System.Guid  1   static 0000000000000000 _globalTransactionTMID
00007f94027e84f0  40003a9       80 ...GroupProviderInfo  0 instance 00007f91381052a8 _poolGroupProviderInfo
00007f94027ef6a8  40003aa       88 ...lClient.TdsParser  0 instance 00007f8db9bfcdb0 _parser
00007f940292f5d8  40003ab       90 ...lient.SqlLoginAck  0 instance 00007f8db9c83420 _loginAck
00007f94027e0958  40003ac       98 ...ent.SqlCredential  0 instance 0000000000000000 _credential
00007f93fef72020  40003ad       7b       System.Boolean  1 instance                1 _sessionRecoveryRequested
00007f93fef72020  40003ae      108       System.Boolean  1 instance                1 _sessionRecoveryAcknowledged
00007f94027f4b58  40003af       a0 ...lient.SessionData  0 instance 00007f8db9bfc360 _currentSessionData
00007f94027f4b58  40003b0       a8 ...lient.SessionData  0 instance 0000000000000000 _recoverySessionData
00007f93fef72020  40003b2      109       System.Boolean  1 instance                1 _fConnectionOpen
00007f93fef72020  40003b3      10a       System.Boolean  1 instance                1 _fResetConnection
00007f93fef6f820  40003b4       b0        System.String  0 instance 00007f8db9c833a0 _originalDatabase
00007f93fef6f820  40003b5       b8        System.String  0 instance 0000000000000000 _currentFailoverPartner
00007f93fef6f820  40003b6       c0        System.String  0 instance 00007f8db9c833f0 _originalLanguage
00007f93fef6f820  40003b7       c8        System.String  0 instance 00007f8db9c833f0 _currentLanguage
00007f93fef76a68  40003b8       7c         System.Int32  1 instance             8000 _currentPacketSize
00007f93fef76a68  40003b9      100         System.Int32  1 instance                0 _asyncCommandCount
00007f93fef6f820  40003ba       d0        System.String  0 instance 00007f90b7fff3c0 _instanceName
00007f94027e3c38  40003bb       d8 ...ctionPoolIdentity  0 instance 00007f9138105348 _identity
00007f94027f4fb0  40003bc       e0 ...Tds+SyncAsyncLock  0 instance 00007f8db9bfc2d8 _parserLock
00007f93fef76a68  40003bd      104         System.Int32  1 instance               -1 _threadIdOwningParserLock
00007f94027f53d8  40003be       e8 ...eoutErrorInternal  0 instance 00007f8db9bfccc8 _timeoutErrorInternal
00007f93fef778b0  40003bf      110          System.Guid  1 instance 00007f8db9bfc2b0 _clientConnectionId
00007f94027f5bf8  40003c0       f0 ...lient.RoutingInfo  0 instance 0000000000000000 _routingInfo
00007f93fef778b0  40003c1      120          System.Guid  1 instance 00007f8db9bfc2c0 _originalClientConnectionId
00007f93fef6f820  40003c2       f8        System.String  0 instance 0000000000000000 _routingDestination
00007f9402e57720  40003b1      3a8 ...Private.CoreLib]]  0   static 0000000000000000 s_transientErrors

(lldb) dumpobj 0x00007f8db9bfc2d8
Name:        System.Data.SqlClient.SqlInternalConnectionTds+SyncAsyncLock
MethodTable: 00007f94027f4fb0
EEClass:     00007f94028031f8
Size:        24(0x18) bytes
File:        .../runtimes/unix/lib/netstandard2.0/System.Data.SqlClient.dll
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00007f93fef7c9f8  4000b62        8 ...ing.SemaphoreSlim  0 instance 00007f8db9bfc2f0 _semaphore

Bug! Waiting for Customer Needs more Info

Most helpful comment

As a precision, it seems that ExecuteSqlBatch acquires a lock on _parserLock.Wait (which translates into a Monitor.Enter on a SemaphoreSlim), then tries to lock TdsParserStateObject (in ExecuteFlush).
Meanwhile, a timer ticks and executes OnTimeout. This method locks TdsParserStateObject then tries to acquire the lock on _parserLock.Wait.

ExecuteSqlBatch:

  1. _parserLock.Wait
  2. lock(TdsParserStateObject)

OnTimeout

  1. lock(TdsParserStateObject)
  2. _parserLock.Wait

We haven't been able to figure out why it's happening so often in our environment and why only on Linux, but this is clearly a deadlock condition.

All 6 comments

As a precision, it seems that ExecuteSqlBatch acquires a lock on _parserLock.Wait (which translates into a Monitor.Enter on a SemaphoreSlim), then tries to lock TdsParserStateObject (in ExecuteFlush).
Meanwhile, a timer ticks and executes OnTimeout. This method locks TdsParserStateObject then tries to acquire the lock on _parserLock.Wait.

ExecuteSqlBatch:

  1. _parserLock.Wait
  2. lock(TdsParserStateObject)

OnTimeout

  1. lock(TdsParserStateObject)
  2. _parserLock.Wait

We haven't been able to figure out why it's happening so often in our environment and why only on Linux, but this is clearly a deadlock condition.

It only happens on Linux because windows and Linux don't use the same TdsStateParserObject implementation, Linux uses Managed while windows uses Native (unless you're using UAP) I was looking through this codebase last night and was wondering why all the locking was there

I've tried to look through this and the locking and callback behaviour in there is giving me a major headache. I suspect the "easy" fix is to lock(this) in TdsExecuteSQLBatch, going one better since that piece of code selectively deals with the parserlock it could directly use Monitor.Enter before the parser lock is taken but then I've no idea what happens with the async cases.

I thought locking this was a bad idea in general.

As recently announced in the .NET Blog, focus on new SqlClient features an improvements is moving to the new Microsoft.Data.SqlClient package. For this reason, we are moving this issue to the new repo at https://github.com/dotnet/SqlClient. We will still use https://github.com/dotnet/corefx to track issues on other providers like System.Data.Odbc and System.Data.OleDB, and general ADO.NET and .NET data access issues.

@crntn , I am following up on this issue to see if you still facing the problem and if the answer is yes, can you kindly provide use a repro please? It makes it easier to investigate while we are looking in the same code.

Hi @crntn ,
We are closing this one due to lacking information. Please feel free to reopen this if you are still facing the issue with the latest Microsoft.Data.SqlClient. A possible repro will be helpful.

Thanks,

Was this page helpful?
0 / 5 - 0 ratings