SQL Connection Timeout 디버깅 with BizTalk Server
 
 
SQL Server는 사용자 연결에 대하여 커넥션 풀을 사용한다. 커넥션 풀은 하나의 커넥션에 대해 100개의 풀이 할당(.NET 경우)되어 사용된다.
 
 
이번 포스트는 CSS SQL Server Engineer 팀블로그에 게시된 내용으로 BizTalk 2006R2 서버에서 발생한 연결시간 오류에 원인을 메모리 덤프를 이용하여 찾는 방법이다. 필자가 읽고 이해한 내용을 정리하였으며 번역의 오류나 기술적 오류가 있음을 미리 알려둔다. 자세한 내용은 원문을 참고하길 바란다.
 
SQL Server에서 커넥션 풀을 모두 소진한 경우 다음과 같은 경고가 발생 한다.
| Exception type: System.InvalidOperationExceptionMessage: 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()
 | 
 
하지만 이번 이슈는 커넥션 풀이 모두 소진되지 않았음에도 불구 하고 다음과 같은 에러가 발생하였으며 BizTalk 2006 R2 서버에서 발생하였다.
| 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
 | 
 
최종 결과는 해당 커넥션 스트링에서 연결 시간을 증가시키거나 SQL Server 연결을 만족시키지 못하는 이유를 확인하는 것이다. SQL Server의 기본 연결 제한 시간은 15초 이다.
 
문제의 원인을 찾기 위해 메모리 덤프를 이용하였다. 디버깅 명령어는 64bit 덤프를 기준으로 하였으며 32bit 경우에도 방법은 유사하다. 우리는 .NET 프레임워크에서 제공되는 SOS 디버깅 확장을 사용했다. 
 
다음 명령을 사용하여 디버거를 확장 하였다.
| 0:000> .loadby sos mscorwks | 
 
덤프에 있는 연결 풀을 살펴보자.
| 0:138>! dumpheap 스탯
									유형 DbConnectionPool
								 000006428281fce8 4 416 System.Data.ProviderBase.DbConnectionPool+TransactedConnectionPool
								000006428281fce8 4 416 System.Data.ProviderBase.DbConnectionPool + TransactedConnectionPool
								000006428085dbc8 28 672 System.Data.ProviderBase.DbConnectionPoolCounters+Counter
								000006428085dbc8 28 672 System.Data.ProviderBase.DbConnectionPoolCounters + 카운터
 000006428281f6d8 8 704 System.Data.ProviderBase.DbConnectionPool+PoolWaitHandles
								000006428281f6d8 8 704 System.Data.ProviderBase.DbConnectionPool + PoolWaitHandles
 0000064282810450 4 704 System.Data.ProviderBase.DbConnectionPool
									0000064282810450 4 704 System.Data.ProviderBase.DbConnectionPool
 000006428281d320 165 5280 System.Data.ProviderBase.DbConnectionPoolIdentity
										000006428281d320 165 5280 System.Data.ProviderBase.DbConnectionPoolIdentity
 | 
 
아래 내용은 MethodTable의 내용으로 다른 항목으로 이동하는데 사용한다. 참고로 여러 항목을 볼 수 있으며 각각을 통해 이동 할 수 있다.
| 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
 | 
 
4개의 풀이 있었으며 얼마나 많은 연결이 있었는지 살펴보자.
| Pool1 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 0000000160036608Name: 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 0x00000000e05add10Name: 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 e05ad798Name: 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 0x000000014004b1d8Name: 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 d01e8288Name: 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 0x00000001502e6af0Name: 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
 | 
 
커넥션 풀은 사용되는 연결 문자열에 의해서 결정된다. 그래서 4개의 다른 연결 문자열이 사용되었음을 의미한다. 우리는 좀 더 많은 정보를 보기 위해서 스택 정보를 확인하였다.
| 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
 ...
 | 
 
이 부분이 예외가 발생한 SQL 명령어 부분이다.
| 0:138> !do 000000015050d780Name: 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
 …
 | 
 
우리는 SQL Connetion Pool이 유효하지 않다는 것을 알았다.
| 0:138> !do 00000001505112d0Name: 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
 | 
 
우리는 최대 풀의 크기를 확인 할 수 있었다. 전체 풀의 입력을 살펴보자.
| 0:138> !do 0x000000014004b1d8Name: 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
 | 
 
첫 번째로 우리가 찾고 있는 풀에 대한 커넥션 스트링을 스택에서 볼 수 있다.
| 0:138> !do 00000000d01e82b0Name: 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 0000000170021600Name: 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 0000000150020230Name: 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
 | 
 
우리는 이제 풀에 대한 오류를 확인 할 수 있다.
| 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
 | 
 
지금까지 디버깅을 통해 확인 한 결과 정상적인 연결의 시간 초과 오류였다. 하지만 풀이 모두 소진되지 않았다. 그들은 커넥션 연결 시간을 25초로 설정 하였다. 이처럼 덤프를 이용하면 많은 정보를 확인 할 수 있다. 
 
 
[참고자료]
http://blogs.msdn.com/b/psssql/archive/2013/10/22/sql-connection-pool-timeout-debugging.aspx
	
 
 
2013-10-23 / 강성욱 / http://sqlmvp.kr