CSS SQL Server Engineers

This is the official team Web Log for Microsoft Customer Service and Support (CSS) SQL Support. Posts are provided by the CSS SQL Escalation Services

SQL Connection Pool Timeout Debugging

SQL Connection Pool Timeout Debugging

Rate This
  • Comments 2

This is a follow up to two blog posts from back in 2009 which talked about leaked connections.  In Part 1 and Part 2 of that post, it was about how to determine that you actually filled your pool.  This was centered around the following error:

Exception type: System.InvalidOperationException
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.
InnerException: <none>
StackTrace (generated):
    SP               IP               Function
    000000001454DDC0 00000642828425A8 System.Data.ProviderBase.DbConnectionFactory.GetConnection(System.Data.Common.DbConnection)
    000000001454DE10 0000064282841BA2 System.Data.ProviderBase.DbConnectionClosed.OpenConnection(System.Data.Common.DbConnection, System.Data.ProviderBase.DbConnectionFactory)
    000000001454DE60 000006428284166C System.Data.SqlClient.SqlConnection.Open()

The issue I just worked on was the same exception, but in the case the Pools were not exhausted. In this case, the issue was occurring within BizTalk 2006 R2.  We narrowed this down to the following exception:

0:138> !pe e09e13f0
Exception object: 00000000e09e13f0
Exception type: System.Data.SqlClient.SqlException
Message: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
InnerException: <none>
StackTrace (generated):
    SP               IP               Function
    0000000015CBDF10 00000642828554A3 System_Data!System.Data.SqlClient.SqlInternalConnection.OnError(System.Data.SqlClient.SqlException, Boolean)+0x103
    0000000015CBDF60 0000064282854DA6 System_Data!System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(System.Data.SqlClient.TdsParserStateObject)+0xf6
    0000000015CBDFC0 0000064282CDCCF1 System_Data!System.Data.SqlClient.TdsParserStateObject.ReadSniError(System.Data.SqlClient.TdsParserStateObject, UInt32)+0x291
    0000000015CBE0A0 000006428284ECCA System_Data!System.Data.SqlClient.TdsParserStateObject.ReadSni(System.Data.Common.DbAsyncResult, System.Data.SqlClient.TdsParserStateObject)+0x13a
    0000000015CBE140 000006428284E9E1 System_Data!System.Data.SqlClient.TdsParserStateObject.ReadNetworkPacket()+0x91
    0000000015CBE1A0 0000064282852763 System_Data!System.Data.SqlClient.TdsParserStateObject.ReadBuffer()+0x33
    0000000015CBE1D0 00000642828526A1 System_Data!System.Data.SqlClient.TdsParserStateObject.ReadByte()+0x21
    0000000015CBE200 0000064282851B5C System_Data!System.Data.SqlClient.TdsParser.Run(System.Data.SqlClient.RunBehavior, System.Data.SqlClient.SqlCommand, System.Data.SqlClient.SqlDataReader, System.Data.SqlClient.BulkCopySimpleResultSet, System.Data.SqlClient.TdsParserStateObject)+0xbc
    0000000015CBE2D0 00000642828519E6 System_Data!System.Data.SqlClient.SqlInternalConnectionTds.CompleteLogin(Boolean)+0x36
    0000000015CBE320 000006428284A997 System_Data!System.Data.SqlClient.SqlInternalConnectionTds.AttemptOneLogin(System.Data.SqlClient.ServerInfo, System.String, Boolean, Int64, System.Data.SqlClient.SqlConnection)+0x147
    0000000015CBE3C0 000006428284859F System_Data!System.Data.SqlClient.SqlInternalConnectionTds.LoginNoFailover(System.String, System.String, Boolean, System.Data.SqlClient.SqlConnection, System.Data.SqlClient.SqlConnectionString, Int64)+0x52f
    0000000015CBE530 0000064282847505 System_Data!System.Data.SqlClient.SqlInternalConnectionTds.OpenLoginEnlist(System.Data.SqlClient.SqlConnection, System.Data.SqlClient.SqlConnectionString, System.String, Boolean)+0x135
    0000000015CBE5D0 00000642828471E3 System_Data!System.Data.SqlClient.SqlInternalConnectionTds..ctor(System.Data.ProviderBase.DbConnectionPoolIdentity, System.Data.SqlClient.SqlConnectionString, System.Object, System.String, System.Data.SqlClient.SqlConnection, Boolean)+0x153
    0000000015CBE670 0000064282846E36 System_Data!System.Data.SqlClient.SqlConnectionFactory.CreateConnection(System.Data.Common.DbConnectionOptions, System.Object, System.Data.ProviderBase.DbConnectionPool, System.Data.Common.DbConnection)+0x296
    0000000015CBE730 0000064282846947 System_Data!System.Data.ProviderBase.DbConnectionFactory.CreatePooledConnection(System.Data.Common.DbConnection, System.Data.ProviderBase.DbConnectionPool, System.Data.Common.DbConnectionOptions)+0x37
    0000000015CBE790 000006428284689D System_Data!System.Data.ProviderBase.DbConnectionPool.CreateObject(System.Data.Common.DbConnection)+0x29d
    0000000015CBE830 000006428292905D System_Data!System.Data.ProviderBase.DbConnectionPool.UserCreateRequest(System.Data.Common.DbConnection)+0x5d
    0000000015CBE870 0000064282846412 System_Data!System.Data.ProviderBase.DbConnectionPool.GetConnection(System.Data.Common.DbConnection)+0x6b2
    0000000015CBE930 00000642828424B4 System_Data!System.Data.ProviderBase.DbConnectionFactory.GetConnection(System.Data.Common.DbConnection)+0x54
    0000000015CBE980 0000064282841BA2 System_Data!System.Data.ProviderBase.DbConnectionClosed.OpenConnection(System.Data.Common.DbConnection, System.Data.ProviderBase.DbConnectionFactory)+0xf2
    0000000015CBE9D0 000006428284166C System_Data!System.Data.SqlClient.SqlConnection.Open()+0x10c
    0000000015CBEA60 0000064282928C2D Microsoft_BizTalk_Bam_EventObservation!Microsoft.BizTalk.Bam.EventObservation.DirectEventStream.StoreSingleEvent(Microsoft.BizTalk.Bam.EventObservation.IPersistQueryable)+0x8d
    0000000015CBEAE0 0000064282928947 Microsoft_BizTalk_Bam_EventObservation!Microsoft.BizTalk.Bam.EventObservation.DirectEventStream.StoreCustomEvent(Microsoft.BizTalk.Bam.EventObservation.IPersistQueryable)+0x47

The end result was to either increase the connection timeout for that connection string, or to look at the performance on the SQL Server and determine why SQL wasn’t able to satisfy the connection.  The customer had indicated that this occurred at the month end operations, which probably means that we ramped up pressure on SQL Server.  It may have come down to us not having enough Workers within SQL to handle the connection request which resulted in a Timeout after the default timeout which is 15 seconds.

Techie details:

This will look at how we determined what the problem was once we had a memory dump of the process. These debugging instructions are based on a 64-bit dump.  The steps should be similar for a 32-bit dump as well.  For the dumps, we used the SOS debugging extension which ships with the .NET Framework.  You can load the extension in the debugger by using the following command:

0:000> .loadby sos mscorwks

Let’s first find the Connection Pools that are in the dump:

0:138> !dumpheap -stat -type DbConnectionPool

000006428281fce8        4          416 System.Data.ProviderBase.DbConnectionPool+TransactedConnectionPool
000006428085dbc8       28          672 System.Data.ProviderBase.DbConnectionPoolCounters+Counter
000006428281f6d8        8          704 System.Data.ProviderBase.DbConnectionPool+PoolWaitHandles
0000064282810450        4          704 System.Data.ProviderBase.DbConnectionPool
000006428281d320      165         5280 System.Data.ProviderBase.DbConnectionPoolIdentity

This shows the MethodTable that we can use to go get the different items.  Of note, you may see multiple items, and may have to go through each one.

0:138> !dumpheap -mt 0x0000064282810450
------------------------------
Heap 4
         Address               MT     Size
00000000c021b348 0000064282810450      176    
total 1 objects
------------------------------
Heap 6
         Address               MT     Size
00000000e05add10 0000064282810450      176    
total 1 objects
------------------------------
Heap 12
         Address               MT     Size
000000014004b1d8 0000064282810450      176    
total 1 objects
------------------------------
Heap 13
         Address               MT     Size
00000001502e6af0 0000064282810450      176
 

We have 4 pools.  Let’s have a look at each pool and see how many connections we have for each.

Pool 1:

0:138> !do 0x00000000c021b348
Name: System.Data.ProviderBase.DbConnectionPool
MethodTable: 0000064282810450
EEClass: 00000642827da538
Size: 176(0xb0) bytes
(C:\WINDOWS\assembly\GAC_64\System.Data\2.0.0.0__b77a5c561934e089\System.Data.dll)
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name

00000642827ef760  400153f       18 ...nnectionPoolGroup  0 instance 0000000160036630 _connectionPoolGroup
0000064282818d18  4001540       20 ...nPoolGroupOptions  0 instance 0000000160036608 _connectionPoolGroupOptions

000006427843d998  4001551       98         System.Int32  1 instance                7 _totalObjects <-- Only 7 Objects out of a total pool size of 500

0:138> !do 0000000160036608
Name: System.Data.ProviderBase.DbConnectionPoolGroupOptions
MethodTable: 0000064282818d18
EEClass: 000006428282ce58
Size: 40(0x28) bytes
(C:\WINDOWS\assembly\GAC_64\System.Data\2.0.0.0__b77a5c561934e089\System.Data.dll)
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00000642784358f8  4001598       14       System.Boolean  1 instance                1 _poolByIdentity
000006427843d998  4001599        8         System.Int32  1 instance                1 _minPoolSize
000006427843d998  400159a        c         System.Int32  1 instance              500 _maxPoolSize <-- Total pool size

Pool 2:

0:138> !do 0x00000000e05add10
Name: System.Data.ProviderBase.DbConnectionPool
0000064282818d18  4001540       20 ...nPoolGroupOptions  0 instance         e05ad798 _connectionPoolGroupOptions
000006427843d998  4001551       98         System.Int32  1 instance                6 _totalObjects <-- Only 6 Objects out of a total pool size of 100

0:138> !do e05ad798
Name: System.Data.ProviderBase.DbConnectionPoolGroupOptions
              MT            Field           Offset                 Type VT             Attr            Value Name
00000642784358f8  4001598       14       System.Boolean  1 instance                1 _poolByIdentity
000006427843d998  4001599        8         System.Int32  1 instance                0 _minPoolSize
000006427843d998  400159a        c         System.Int32  1 instance              100 _maxPoolSize <-- Total pool size

Pool 3:

0:138> !do 0x000000014004b1d8
Name: System.Data.ProviderBase.DbConnectionPool
0000064282818d18  4001540       20 ...nPoolGroupOptions  0 instance         d01e8288 _connectionPoolGroupOptions
000006427843d998  4001551       98         System.Int32  1 instance                7 _totalObjects <-- Only 7 Objects out of a total pool size of 500

0:138> !do d01e8288
Name: System.Data.ProviderBase.DbConnectionPoolGroupOptions
              MT            Field           Offset                 Type VT             Attr            Value Name
00000642784358f8  4001598       14       System.Boolean  1 instance                1 _poolByIdentity
000006427843d998  4001599        8         System.Int32  1 instance                1 _minPoolSize
000006427843d998  400159a        c         System.Int32  1 instance              500 _maxPoolSize <-- Total pool size

Pool 4:

0:138> !do 0x00000001502e6af0
Name: System.Data.ProviderBase.DbConnectionPool
0000064282818d18  4001540       20 ...nPoolGroupOptions  0 instance        1600f1940 _connectionPoolGroupOptions
000006427843d998  4001551       98         System.Int32  1 instance                4 _totalObjects <-- Only 4 Objects out of a total pool size of 100

0:138> !do 1600f1940
Name: System.Data.ProviderBase.DbConnectionPoolGroupOptions
              MT            Field           Offset                 Type VT             Attr            Value Name
00000642784358f8  4001598       14       System.Boolean  1 instance                1 _poolByIdentity
000006427843d998  4001599        8         System.Int32  1 instance                0 _minPoolSize
000006427843d998  400159a        c         System.Int32  1 instance              100 _maxPoolSize <-- Total pool size

The connection pools are dictated by the Connection String used.  So, this means 4 different connection strings were used.  We can look at the stack objects to see if we can pick apart some more information.

0:138> !dso
OS Thread Id: 0x70b0 (138)
RSP/REG          Object           Name
...
000000001454df30 00000001602a0f00 System.Data.SqlClient.SqlConnection
000000001454df40 00000000c0ace890 System.String
000000001454df48 00000001602a0cf0 Microsoft.BizTalk.Bam.EventObservation.BAMTraceFragment
000000001454df50 0000000150511568 System.String
000000001454df60 00000001602a0b00 Microsoft.BizTalk.Bam.EventObservation.DirectEventStream
000000001454df70 00000001602a0b00 Microsoft.BizTalk.Bam.EventObservation.DirectEventStream
000000001454df78 00000001602a0cf0 Microsoft.BizTalk.Bam.EventObservation.BAMTraceFragment
000000001454df80 00000001505112d0 System.String
000000001454df88 0000000150511568 System.String
000000001454df90 00000001602a0cf0 Microsoft.BizTalk.Bam.EventObservation.BAMTraceFragment
000000001454dfa8 00000001602a13d0 System.InvalidOperationException
000000001454dfb0 00000001602a0b38 System.Object
000000001454dfb8 000000015050d780 System.Data.SqlClient.SqlCommand
...

Here is the SQL Command Object that was issuing the command when we had the exception.

0:138> !do 000000015050d780
Name: System.Data.SqlClient.SqlCommand
MethodTable: 000006428279dbd0
EEClass: 00000642827d1dc0
Size: 224(0xe0) bytes
(C:\WINDOWS\assembly\GAC_64\System.Data\2.0.0.0__b77a5c561934e089\System.Data.dll)
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
0000064278436018  400018a        8        System.Object  0 instance 0000000000000000 __identity
00000642828144d8  40008de       10 ...ponentModel.ISite  0 instance 0000000000000000 site
00000642826664d8  40008df       18 ....EventHandlerList  0 instance 0000000000000000 events
0000064278436018  40008dd      210        System.Object  0   static 00000000f0269548 EventDisposed
000006427843d998  40016f2       b0         System.Int32  1 instance              672 ObjectID
0000064278436728  40016f3       20        System.String  0 instance 00000000f0020178 _commandText <-- The query/command issued
000006428279c370  40016f4       b4         System.Int32  1 instance                4 _commandType
000006427843d998  40016f5       b8         System.Int32  1 instance               30 _commandTimeout
000006428279d908  40016f6       bc         System.Int32  1 instance                3 _updatedRowSource
00000642784358f8  40016f7       d0       System.Boolean  1 instance                0 _designTimeInvisible
000006428288d490  40016f8       28 ...ent.SqlDependency  0 instance 0000000000000000 _sqlDep
00000642784358f8  40016f9       d1       System.Boolean  1 instance                0 _inPrepare
000006427843d998  40016fa       c0         System.Int32  1 instance               -1 _prepareHandle
00000642784358f8  40016fb       d2       System.Boolean  1 instance                0 _hiddenPrepare
00000642827e3128  40016fc       30 ...rameterCollection  0 instance 000000015050d940 _parameters
00000642827eea48  40016fd       38 ...ent.SqlConnection  0 instance 000000015050f308 _activeConnection <-- The SqlConnection that we used for this command
00000642784358f8  40016fe       d3       System.Boolean  1 instance                0 _dirty

In this case, we know the SqlConnection isn’t valid because we erred trying to get it from the Pool.  The Command Text would be interesting has this been a Query timeout, but for a connection Timeout, it is irrelevant.  We can poke at the strings on the stack and we will find the Connection String used for this operation.

0:138> !do 00000001505112d0
Name: System.String
MethodTable: 0000064278436728
EEClass: 000006427803e520
Size: 330(0x14a) bytes
(C:\WINDOWS\assembly\GAC_64\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll)
String: server=MyServer; database= MyDatabase;Integrated Security=SSPI;Connect Timeout=25; pooling=true; Max Pool Size=500; Min Pool Size=1

From this, we can see Max Pool Size is at 500, so that narrows it down to two of the four Pools listed above. When we went through the pools previously, I noticed that one of the pools had something that the others didn’t.  And, it happened to be one of the pools with the Pool Size of 500.  Let’s look at the full input of the pool in question.

0:138> !do 0x000000014004b1d8
Name: System.Data.ProviderBase.DbConnectionPool
MethodTable: 0000064282810450
EEClass: 00000642827da538
Size: 176(0xb0) bytes
(C:\WINDOWS\assembly\GAC_64\System.Data\2.0.0.0__b77a5c561934e089\System.Data.dll)
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
000006427843d998  400153c       88         System.Int32  1 instance           200000 _cleanupWait
000006428281d320  400153d        8 ...ctionPoolIdentity  0 instance 000000014004b1b8 _identity
00000642827ef2d0  400153e       10 ...ConnectionFactory  0 instance 0000000140022860 _connectionFactory
00000642827ef760  400153f       18 ...nnectionPoolGroup  0 instance 00000000d01e82b0 _connectionPoolGroup <-- We can get the connection string from this object
0000064282818d18  4001540       20 ...nPoolGroupOptions  0 instance 00000000d01e8288 _connectionPoolGroupOptions
000006428281d3c0  4001541       28 ...nPoolProviderInfo  0 instance 0000000000000000 _connectionPoolProviderInfo
00000642828102f8  4001542       8c         System.Int32  1 instance                1 _state
000006428281d4b8  4001543       30 ...InternalListStack  0 instance 000000014004b288 _stackOld
000006428281d4b8  4001544       38 ...InternalListStack  0 instance 000000014004b2a0 _stackNew
0000064278424d50  4001545       40 ...ding.WaitCallback  0 instance 000000014004c570 _poolCreateRequest
0000064278425c90  4001546       48 ...Collections.Queue  0 instance 0000000000000000 _deactivateQueue
0000064278424d50  4001547       50 ...ding.WaitCallback  0 instance 0000000000000000 _deactivateCallback
000006427843d998  4001548       90         System.Int32  1 instance                0 _waitCount
000006428281f6d8  4001549       58 ...l+PoolWaitHandles  0 instance 000000014004b3a8 _waitHandles
00000642784369f0  400154a       60     System.Exception  0 instance 00000000e09e13f0 _resError <-- We had an error on this pool
00000642784358f8  400154b       a0       System.Boolean  1 instance                1 _errorOccurred
000006427843d998  400154c       94         System.Int32  1 instance            10000 _errorWait
0000064278468a80  400154d       68 ...m.Threading.Timer  0 instance 00000001505bc420 _errorTimer
0000064278468a80  400154e       70 ...m.Threading.Timer  0 instance 000000014004c5f0 _cleanupTimer
000006428281fce8  400154f       78 ...tedConnectionPool  0 instance 000000014004c3e8 _transactedConnectionPool
0000000000000000  4001550       80                       0 instance 000000014004b400 _objectList
000006427843d998  4001551       98         System.Int32  1 instance                7 _totalObjects
000006427843d998  4001553       9c         System.Int32  1 instance                8 _objectID
0000064278425e20  400153b      c00        System.Random  0   static 00000000e0188968 _random
000006427843d998  4001552      968         System.Int32  1   static               18 _objectTypeCount

First, lets see if we can line up the connection string for this Pool with what was on the stack to make sure we are looking at the right pool.

0:138> !do 00000000d01e82b0
Name: System.Data.ProviderBase.DbConnectionPoolGroup
MethodTable: 00000642827ef760
EEClass: 00000642827da418
Size: 72(0x48) bytes
(C:\WINDOWS\assembly\GAC_64\System.Data\2.0.0.0__b77a5c561934e089\System.Data.dll)
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
0000064282816978  4001584        8 ...ConnectionOptions  0 instance 0000000170021600 _connectionOptions
0000064282818d18  4001585       10 ...nPoolGroupOptions  0 instance 00000000d01e8288 _poolGroupOptions
00000642823f2650  4001586       18 ....HybridDictionary  0 instance 00000000b00fb528 _poolCollection
000006427843d998  4001587       30         System.Int32  1 instance                1 _poolCount
000006427843d998  4001588       34         System.Int32  1 instance                1 _state
00000642828193b0  4001589       20 ...GroupProviderInfo  0 instance 00000000d01e82f8 _providerInfo
0000000000000000  400158a       28 ...DbMetaDataFactory  0 instance 0000000000000000 _metaDataFactory
000006427843d998  400158c       38         System.Int32  1 instance                7 _objectID
000006427843d998  400158b      978         System.Int32  1   static               20 _objectTypeCount

0:138> !do 0000000170021600
Name: System.Data.SqlClient.SqlConnectionString
MethodTable: 0000064282817158
EEClass: 00000642828234e0
Size: 184(0xb8) bytes
(C:\WINDOWS\assembly\GAC_64\System.Data\2.0.0.0__b77a5c561934e089\System.Data.dll)
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
0000064278436728  4000bef        8        System.String  0 instance 0000000150020230 _usersConnectionString
000006427843e080  4000bf0       10 ...ections.Hashtable  0 instance 00000001700216b8 _parsetable
00000642828180a0  4000bf1       18 ...mon.NameValuePair  0 instance 0000000170021878 KeyChain
00000642784358f8  4000bf2       28       System.Boolean  1 instance                0 HasPasswordKeyword
00000642784358f8  4000bf3       29       System.Boolean  1 instance                0 UseOdbcRules
000006427843cf18  4000bf4       20 ...ity.PermissionSet  0 instance 00000000d01e8330 _permissionset
00000642825a4958  4000beb      3e0 ...Expressions.Regex  0   static 00000000f026d658 ConnectionStringValidKeyRegex
00000642825a4958  4000bec      3e8 ...Expressions.Regex  0   static 00000000d01e7798 ConnectionStringValidValueRegex
00000642825a4958  4000bed      3f0 ...Expressions.Regex  0   static 0000000080032770 ConnectionStringQuoteValueRegex
00000642825a4958  4000bee      3f8 ...Expressions.Regex  0   static 0000000080034800 ConnectionStringQuoteOdbcValueRegex

0:138> !do 0000000150020230
Name: System.String
MethodTable: 0000064278436728
EEClass: 000006427803e520
Size: 330(0x14a) bytes
(C:\WINDOWS\assembly\GAC_64\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll)
String: server=MyServer; database= MyDatabase;Integrated Security=SSPI;Connect Timeout=25; pooling=true; Max Pool Size=500; Min Pool Size=1

We have a match!  So, now lets look at the error that was on the pool.

0:138> !pe 00000000e09e13f0
Exception object: 00000000e09e13f0
Exception type: System.Data.SqlClient.SqlException
Message: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
InnerException: <none>
StackTrace (generated):
    SP               IP               Function
    0000000015CBDF10 00000642828554A3 System_Data!System.Data.SqlClient.SqlInternalConnection.OnError(System.Data.SqlClient.SqlException, Boolean)+0x103
    0000000015CBDF60 0000064282854DA6 System_Data!System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(System.Data.SqlClient.TdsParserStateObject)+0xf6
    0000000015CBDFC0 0000064282CDCCF1 System_Data!System.Data.SqlClient.TdsParserStateObject.ReadSniError(System.Data.SqlClient.TdsParserStateObject, UInt32)+0x291
    0000000015CBE0A0 000006428284ECCA System_Data!System.Data.SqlClient.TdsParserStateObject.ReadSni(System.Data.Common.DbAsyncResult, System.Data.SqlClient.TdsParserStateObject)+0x13a
    0000000015CBE140 000006428284E9E1 System_Data!System.Data.SqlClient.TdsParserStateObject.ReadNetworkPacket()+0x91
    0000000015CBE1A0 0000064282852763 System_Data!System.Data.SqlClient.TdsParserStateObject.ReadBuffer()+0x33
    0000000015CBE1D0 00000642828526A1 System_Data!System.Data.SqlClient.TdsParserStateObject.ReadByte()+0x21
    0000000015CBE200 0000064282851B5C System_Data!System.Data.SqlClient.TdsParser.Run(System.Data.SqlClient.RunBehavior, System.Data.SqlClient.SqlCommand, System.Data.SqlClient.SqlDataReader, System.Data.SqlClient.BulkCopySimpleResultSet, System.Data.SqlClient.TdsParserStateObject)+0xbc
    0000000015CBE2D0 00000642828519E6 System_Data!System.Data.SqlClient.SqlInternalConnectionTds.CompleteLogin(Boolean)+0x36
    0000000015CBE320 000006428284A997 System_Data!System.Data.SqlClient.SqlInternalConnectionTds.AttemptOneLogin(System.Data.SqlClient.ServerInfo, System.String, Boolean, Int64, System.Data.SqlClient.SqlConnection)+0x147
    0000000015CBE3C0 000006428284859F System_Data!System.Data.SqlClient.SqlInternalConnectionTds.LoginNoFailover(System.String, System.String, Boolean, System.Data.SqlClient.SqlConnection, System.Data.SqlClient.SqlConnectionString, Int64)+0x52f
    0000000015CBE530 0000064282847505 System_Data!System.Data.SqlClient.SqlInternalConnectionTds.OpenLoginEnlist(System.Data.SqlClient.SqlConnection, System.Data.SqlClient.SqlConnectionString, System.String, Boolean)+0x135
    0000000015CBE5D0 00000642828471E3 System_Data!System.Data.SqlClient.SqlInternalConnectionTds..ctor(System.Data.ProviderBase.DbConnectionPoolIdentity, System.Data.SqlClient.SqlConnectionString, System.Object, System.String, System.Data.SqlClient.SqlConnection, Boolean)+0x153
    0000000015CBE670 0000064282846E36 System_Data!System.Data.SqlClient.SqlConnectionFactory.CreateConnection(System.Data.Common.DbConnectionOptions, System.Object, System.Data.ProviderBase.DbConnectionPool, System.Data.Common.DbConnection)+0x296
    0000000015CBE730 0000064282846947 System_Data!System.Data.ProviderBase.DbConnectionFactory.CreatePooledConnection(System.Data.Common.DbConnection, System.Data.ProviderBase.DbConnectionPool, System.Data.Common.DbConnectionOptions)+0x37
    0000000015CBE790 000006428284689D System_Data!System.Data.ProviderBase.DbConnectionPool.CreateObject(System.Data.Common.DbConnection)+0x29d
    0000000015CBE830 000006428292905D System_Data!System.Data.ProviderBase.DbConnectionPool.UserCreateRequest(System.Data.Common.DbConnection)+0x5d
    0000000015CBE870 0000064282846412 System_Data!System.Data.ProviderBase.DbConnectionPool.GetConnection(System.Data.Common.DbConnection)+0x6b2
    0000000015CBE930 00000642828424B4 System_Data!System.Data.ProviderBase.DbConnectionFactory.GetConnection(System.Data.Common.DbConnection)+0x54
    0000000015CBE980 0000064282841BA2 System_Data!System.Data.ProviderBase.DbConnectionClosed.OpenConnection(System.Data.Common.DbConnection, System.Data.ProviderBase.DbConnectionFactory)+0xf2
    0000000015CBE9D0 000006428284166C System_Data!System.Data.SqlClient.SqlConnection.Open()+0x10c
    0000000015CBEA60 0000064282928C2D Microsoft_BizTalk_Bam_EventObservation!Microsoft.BizTalk.Bam.EventObservation.DirectEventStream.StoreSingleEvent(Microsoft.BizTalk.Bam.EventObservation.IPersistQueryable)+0x8d
    0000000015CBEAE0 0000064282928947 Microsoft_BizTalk_Bam_EventObservation!Microsoft.BizTalk.Bam.EventObservation.DirectEventStream.StoreCustomEvent(Microsoft.BizTalk.Bam.EventObservation.IPersistQueryable)+0x47

As we can see, it is a normal Connection Timeout error.  Which makes sense, as our pools were not exhausted.  Of note, they had set their Connection Timeout to 25 seconds in the connection string.  Which means they would need to bump it higher, or look at what is going on with SQL Server at the time this occurs.  Not much more we can get from the dump.

 

Adam W. Saxton | Microsoft Escalation Services
http://twitter.com/awsaxton

Leave a Comment
  • Please add 8 and 5 and type the answer here:
  • Post
  • Thanks for the detailed walk through and analysis.  I have had to do this a couple times and it definitely makes the process of debugging easier seeing what to look at and knowing some of the reasoning behind the results you see.

  • I actually wrote a WinDBG extension to do this.  It dumps all connection pools in the process, along with all the open connections, commands, and SQL being run at the time.  Not to plug my blog, but you can check it out here: www.steveniemitz.com/.../Introducing-SPT-for-NET-45.aspx

Page 1 of 1 (2 items)