최근에 진행된 지원 케이스에서 ASP.Net 페이지의 서비스 속도 저하와 관련된  이슈에서 조금은 특이한 부분이 있어서 정리차원에서 블로그 글을  포스팅 합니다.

 

우선 문제 상황에 대한 간단한 내용을 보면 다음과 같습니다.

 

Windows 2003 서버에 .Net Framework 2.0 (또는 그 이상)이 설치되어 있고 ASP.Net 페이지들은 단순하게 사용자의 입력을 받고 서비스를 호출 한 후 결과를 보여주는 기능을 하고 있습니다. 이때 서비스는 역시 .Net Framework 2.0 C#으로 제작된 Serviced Component 형태로 COM+ 서버에서 작동 중 이었습니다.

 

COM+는 다시 실제 Business Logic을 구현하고 Exchange 2007 메일 서버에 EWS로 접근 하여 ASPX 페이지들이 보여줄 자료를 가공하는 역활을 하도록 제작되어 있습니다.

 

서비스 중에 느끼게 되는 문제의 형태는

1. Peak Time에 CPU나 메모리 사용량이 높거나 많지 않고,

2. netstat 등으로 확인해 보면 IIS 또는 COM+ 프로세스에서 사용하는 Network Connection 역시 많지 않은 상황 있었습니다.

 

어떤 이유에서 인지 서버들이 늘어난 처리 요청에 따라서 적절하게 시스템 리소스를 사용하지 못하고 의도 되지 않은 어떤 설정에 의해서 성능 저하를 가져오는 상태에 있었습니다.

 

문제 확인을 위해서 사용자가 많은 시점에 IIS의 Worker Process (W3WP.EXE)와 COM+ 프로세스 (DLLHOST.EXE)의 행모드 덤프(Hang-mode Debug Dump)를 수집 해서 상태 파악을 시도 했습니다.

 

W3WP.EXE에서 실행되는 모든 사용자 요청은 실제 아래의 형태와 같이 COM+ 서버에 전달된 자료 처리 요청에 대한 결과를 대기 중인 상태에 있었습니다.

 

ESP       EIP    
02c9eee8 7c96860c [ComPlusMethodFrameStandaloneCleanup: 02c9eee8] System.EnterpriseServices.IRemoteDispatch.RemoteDispatchAutoDone(System.String)
02c9eef8 0435ef72 System.EnterpriseServices.RemoteServicedComponentProxy.Invoke(System.Runtime.Remoting.Messaging.IMessage)
02c9ef40 794abdb3 System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(System.Runtime.Remoting.Proxies.MessageData ByRef, Int32)
02c9f1e0 79f3cb53 [TPMethodFrame: 02c9f1e0] SomeBusinessModule.GetDataList(SomeBusinessData.DataEntry, System.String)
02c9f1f4 042a5feb ViewBusinessData.Page_Load(System.Object, System.EventArgs)
02c9f224 698a1928 System.Web.Util.CalliHelper.EventArgFunctionCaller(IntPtr, System.Object, System.Object, System.EventArgs)
02c9f234 0300d73f System.Web.Util.CalliEventHandlerDelegateProxy.Callback(System.Object, System.EventArgs)
02c9f248 02eba5a4 System.Web.UI.Control.OnLoad(System.EventArgs)
02c9f258 042a06cc BasePage.OnLoad(System.EventArgs)
02c9f264 02eba5f0 System.Web.UI.Control.LoadRecursive()
02c9f278 02ecbbf6 System.Web.UI.Page.ProcessRequestMain(Boolean, Boolean)
02c9f430 02ecb521 System.Web.UI.Page.ProcessRequest(Boolean, Boolean)
02c9f460 02ecb487 System.Web.UI.Page.ProcessRequest()
02c9f498 02ecb3a7 System.Web.UI.Page.ProcessRequestWithNoAssert(System.Web.HttpContext)
02c9f4a0 02ecb33a System.Web.UI.Page.ProcessRequest(System.Web.HttpContext)
02c9f4b4 042a0165 ASP.ViewBusinessData_aspx.ProcessRequest(System.Web.HttpContext)
02c9f4b8 02d788df System.Web.HttpApplication+CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
02c9f4ec 02d4a071 System.Web.HttpApplication.ExecuteStep(IExecutionStep, Boolean ByRef)
02c9f52c 02d4a39b System.Web.HttpApplication.ResumeSteps(System.Exception)
02c9f574 02d4912d System.Web.HttpApplication.System.Web.IHttpAsyncHandler.BeginProcessRequest(System.Web.HttpContext, System.AsyncCallback, System.Object)
02c9f590 02d4e0bd System.Web.HttpRuntime.ProcessRequestInternal(System.Web.HttpWorkerRequest)
02c9f5c4 02d4dd72 System.Web.HttpRuntime.ProcessRequestNoDemand(System.Web.HttpWorkerRequest)
02c9f5d0 02d4c447 System.Web.Hosting.ISAPIRuntime.ProcessRequest(IntPtr, Int32)
02c9f780 79f1ef33 [ContextTransitionFrame: 02c9f780]
02c9f7d0 79f1ef33 [GCFrame: 02c9f7d0]
02c9f928 79f1ef33 [ComMethodFrame: 02c9f928]

 

같은 시점에 수집된 DLLHOST.EXE 덤프의 내용을 분석해 봤습니다.

 

우선 프로세스 기본 정보를 보면 서버는 4개의 CPU가 장착되어 있고 운영체제로 Windows 2003 SP2 를 사용하고 있다는 것을 알 수 있습니다.

Windows Server 2003 Version 3790 (Service Pack 2) MP (4 procs) Free x86 compatible
Product: Server, suite: Enterprise TerminalServer SingleUserTS
kernel32.dll version: 5.2.3790.4480 (srv03_sp2_gdr.090321-1244)
Machine Name:
Debug session time: Fri Jul  3 08:18:50.000 2009 (GMT+9)
…

프로세서의 사용 정보와 ThreadPool의 상태를 확인해 보면 사용자 요청이 많은 시간대 임에도 불구 하고 CPU 사용량이 8% 정도 이며 100개 까지 생성 될 수 있는 Worker Thread들 중 실행 중인 Thread가 1개 (Running : 1) 뿐 임을 할 수 있습니다.


Work Request in Queue: 0
--------------------------------------
Number of Timers: 0
--------------------------------------
CPU utilization 8%
--------------------------------------
Worker Thread: Total: 1 Running: 1 Idle: 0 MaxLimit: 100 MinLimit: 4
Completion Port Thread:Total: 0 Free: 0 MaxFree: 8 CurrentLimit: 0 MaxLimit: 1000 MinLimit: 4

문제 확인을 위해서 SyncBlock을 확인해 보니 아래와 같이 많은 숫자의 Thread들이 System.Net.ServicePoint 관련 SyncBlock에 대해 블로킹 된 상태로 사용 Thread의 완료를 기다리는 상태 임을 확인 할 수 있습니다.

 

0:000> !SyncBlk
Index SyncBlock MonitorHeld Recursion Owning Thread Info  SyncBlock Owner
  352 1a3387e4          115         1 1a353728  23e8  17   09332f2c System.Net.ServicePoint
        Waiting threads: 14 15 16 18 20 21 22 23 24 25 26 27 28 30 31 32 33 34 35 36 37 38 …

  353 001728ec            3         1 1a353728  23e8  17   013a2ec8 System.Collections.ArrayList
        Waiting threads: 19
  354 1a391dcc            3         1 00162c70  24b4  19   013a2f1c System.Net.Connection
        Waiting threads: 17
-----------------------------
Total           458
CCW             225
RCW             0
ComClassFactory 0
Free            150

 

실행 중인 Managed Thread들 중에 위의 SyncBlock 리스트의 Head에 해당하는 17번, 19번 Thread의 Call Stack은 아래와 같습니다.

이들은 System.Net.Connection 객체의 사용이 완료되어서 Close/Release를 진행 중인 상태에 있었습니다.

 

0:019> !ClrStack
OS Thread Id: 0x24b4 (19)
ESP       EIP    
1a29f7b0 7c96860c [GCFrame: 1a29f7b0]
1a29f880 7c96860c [HelperMethodFrame_1OBJ: 1a29f880] System.Threading.Monitor.Enter(System.Object)
1a29f8d8 7a5b0034 System.Net.ConnectionGroup.Disassociate(System.Net.Connection)
1a29f904 7a5aeaa7 System.Net.Connection.PrepareCloseConnectionSocket(System.Net.ConnectionReturnResult ByRef)
1a29f968 7a5ae293 System.Net.Connection.AbortOrDisassociate(System.Net.HttpWebRequest, System.Net.WebException)
1a29f9a0 7a57d9ff System.Net.HttpWebRequest.Abort(System.Exception, Int32)
1a29f9d4 7a57dbd1 System.Net.HttpWebRequest.AbortWrapper(System.Object)
1a29f9e8 793d91f6 System.Threading._ThreadPoolWaitCallback.PerformWaitCallback(System.Object)
1a29fb78 79e88f63 [GCFrame: 1a29fb78]

 

0:017> !ClrStack
OS Thread Id: 0x23e8 (17)
ESP       EIP    
00dfe0d4 7c96860c [GCFrame: 00dfe0d4]
00dfe1a4 7c96860c [HelperMethodFrame_1OBJ: 00dfe1a4] System.Threading.Monitor.Enter(System.Object)
00dfe1fc 7a5ae107 System.Net.Connection.CloseOnIdle()
00dfe228 7a5b0403 System.Net.ConnectionGroup.DisableKeepAliveOnConnections()
00dfe25c 7a58be63 System.Net.ServicePoint.ReleaseConnectionGroup(System.String)
00dfe28c 7a5c227f System.Net.NegotiateClient.Update(System.String, System.Net.WebRequest)
00dfe2ac 7a5a43c7 System.Net.AuthenticationState.Update(System.Net.HttpWebRequest)
00dfe2ec 7a57c04c System.Net.HttpWebRequest.DoSubmitRequestProcessing(System.Exception ByRef)
00dfe320 7a57e50a System.Net.HttpWebRequest.ProcessResponse()
00dfe358 7a57e4a3 System.Net.HttpWebRequest.SetResponse(System.Net.CoreResponseData)
00dfe39c 7a57e11a System.Net.HttpWebRequest.CheckWriteSideResponseProcessing()
00dfe3a8 7a57f51e System.Net.HttpWebRequest.EndSubmitRequest()
00dfe3d8 7a57dec6 System.Net.HttpWebRequest.SetRequestSubmitDone(System.Net.ConnectStream)
00dfe3ec 7a5ab8ff System.Net.Connection.CompleteStartRequest(Boolean, System.Net.HttpWebRequest, System.Net.TriState)
00dfe41c 7a5ab56b System.Net.Connection.SubmitRequest(System.Net.HttpWebRequest)
00dfe460 7a58b1b4 System.Net.ServicePoint.SubmitRequest(System.Net.HttpWebRequest, System.String)
00dfe498 7a57ef21 System.Net.HttpWebRequest.SubmitRequest(System.Net.ServicePoint)
00dfe4c8 7a57cae2 System.Net.HttpWebRequest.GetResponse()
00dfe510 6990bf7d System.Web.Services.Protocols.WebClientProtocol.GetWebResponse(System.Net.WebRequest)
00dfe540 6990c915 System.Web.Services.Protocols.HttpWebClientProtocol.GetWebResponse(System.Net.WebRequest)
00dfe544 69919eb1 System.Web.Services.Protocols.SoapHttpClientProtocol.Invoke(System.String, System.Object[])
00dfe588 19aa5560 ExchangeServiceBinding.FindItem(FindItemType)
00dfe598 1a300e14 AccessMailServer.GetMailList(...)
00dfefc8 79e88f63 [HelperMethodFrame_PROTECTOBJ: 00dfefc8] System.Runtime.Remoting.Messaging.StackBuilderSink._PrivateProcessMessage(IntPtr, System.Object[], System.Object, Int32, Boolean, System.Object[] ByRef)
00dff10c 794be820 System.Runtime.Remoting.Messaging.StackBuilderSink.PrivateProcessMessage(System.RuntimeMethodHandle, System.Object[], System.Object, Int32, Boolean, System.Object[] ByRef)
00dff12c 794bdf4b System.Runtime.Remoting.Messaging.StackBuilderSink.SyncProcessMessage(System.Runtime.Remoting.Messaging.IMessage, Int32, Boolean)
00dff1ac 794b6233 System.Runtime.Remoting.RemotingServices.ExecuteMessage(System.MarshalByRefObject, System.Runtime.Remoting.Messaging.IMethodCallMessage)
00dff1bc 673fd83d System.EnterpriseServices.ServicedComponentProxy.LocalInvoke(System.Runtime.Remoting.Messaging.IMessage)
00dff1fc 673fd64e System.EnterpriseServices.ServicedComponentProxy.Invoke(System.Runtime.Remoting.Messaging.IMessage)
00dff20c 673fb5a4 System.EnterpriseServices.ServicedComponent.RemoteDispatchHelper(System.String, Boolean ByRef)
00dff21c 673fb317 System.EnterpriseServices.ServicedComponent.System.EnterpriseServices.IRemoteDispatch.RemoteDispatchAutoDone(System.String)
00dff424 79f1ef33 [GCFrame: 00dff424]
00dff57c 79f1ef33 [ComMethodFrame: 00dff57c]

나머지 Thread들은 전부 아래와 같은 형태로 네트워크 관련 처리를 위해서 System.Net.ServicePoint 객체를 사용하기 위한 Monitor에 대해서 Waiting을 하고 있는 상태 였습니다.

ESP       EIP    
1a90e874 7c96860c [GCFrame: 1a90e874]
1a90e9ac 7c96860c [HelperMethodFrame: 1a90e9ac] System.Threading.Monitor.Enter(System.Object)
1a90ea00 7a58b151 System.Net.ServicePoint.SubmitRequest(System.Net.HttpWebRequest, System.String)
1a90ea38 7a57ef21 System.Net.HttpWebRequest.SubmitRequest(System.Net.ServicePoint)
1a90ea68 7a57bd92 System.Net.HttpWebRequest.GetRequestStream()
1a90ea9c 69919e6c System.Web.Services.Protocols.SoapHttpClientProtocol.Invoke(System.String, System.Object[])
1a90eae0 1a307f60 AccessMailServer.GetItem(GetItemType)
1a90eaf0 1a2f8414 SomeBusinessModule.GetChangedPArts(DataEntry, System.String)
1a90eb2c 1a2f8f74 SomeBusinessModule.Method1(DataEntry, System.String ByRef)
1a90eb84 1a2f2ff9 SomeBusinessModule.SendData(DataEntry, System.String ByRef)
1a90ec40 79e88f63 [ProtectByRefsFrame: 1a90ec40]
1a90efc8 79e88f63 [HelperMethodFrame_PROTECTOBJ: 1a90efc8] System.Runtime.Remoting.Messaging.StackBuilderSink._PrivateProcessMessage(IntPtr, System.Object[], System.Object, Int32, Boolean, System.Object[] ByRef)
1a90f10c 794be820 System.Runtime.Remoting.Messaging.StackBuilderSink.PrivateProcessMessage(System.RuntimeMethodHandle, System.Object[], System.Object, Int32, Boolean, System.Object[] ByRef)
1a90f12c 794bdf4b System.Runtime.Remoting.Messaging.StackBuilderSink.SyncProcessMessage(System.Runtime.Remoting.Messaging.IMessage, Int32, Boolean)
1a90f1ac 794b6233 System.Runtime.Remoting.RemotingServices.ExecuteMessage(System.MarshalByRefObject, System.Runtime.Remoting.Messaging.IMethodCallMessage)
1a90f1bc 673fd83d System.EnterpriseServices.ServicedComponentProxy.LocalInvoke(System.Runtime.Remoting.Messaging.IMessage)
1a90f1fc 673fd64e System.EnterpriseServices.ServicedComponentProxy.Invoke(System.Runtime.Remoting.Messaging.IMessage)
1a90f20c 673fb5a4 System.EnterpriseServices.ServicedComponent.RemoteDispatchHelper(System.String, Boolean ByRef)
1a90f21c 673fb317 System.EnterpriseServices.ServicedComponent.System.EnterpriseServices.IRemoteDispatch.RemoteDispatchAutoDone(System.String)
1a90f424 79f1ef33 [GCFrame: 1a90f424]
1a90f57c 79f1ef33 [ComMethodFrame: 1a90f57c]

 

위현상은 아래의 .Net Framework 성능 조정과 관련된 KB 문서에서 언급하고 있는 Connection 설정인 MaxConnection=2와 유사한 것으로 보입니다.

 

Contention, poor performance, and deadlocks when you make Web service requests from ASP.NET applications
http://support.microsoft.com/kb/821268/en-us

 

덤프에서 확인해 보면 실제 ServicePoint객체에서 확인 가능한 Connection Limit가 2로 설정되어 있음을 확인 할 수 있습니다. 즉, 문제가 되고 있는 현상은 .Net Framework과 관련된 설정이 성능에 문제를 일으키고 있다는 것 입니다. 하지만 위의 KB 문서를 보면 .Net Framework 2.0의 경우는 autoConfig를 설정하는 경우 maxconnection이 12*CPU 갯수라고 지정되어 있으며 문제 서버의 경우 AutoConfig가 Enable 되어 있는 상태 였습니다.

 

Name: System.Net.ServicePoint
MethodTable: 7a772e10
EEClass: 7a7d0b68
Size: 116(0x74) bytes
GC Generation: 2
(C:\WINDOWS\assembly\GAC_MSIL\System\2.0.0.0__b77a5c561934e089\System.dll)
Fields:
      MT    Field   Offset                 Type VT     Attr    Value Name
790fed1c  40020af       38         System.Int32  1 instance       -1 m_ConnectionLeaseTimeout
7a77a4c4  40020b0        4 ...TimerThread+Queue  0 instance 05310044 m_ConnectionLeaseTimerQueue
79104f64  40020b1       54       System.Boolean  1 instance        0 m_ProxyServicePoint
79104f64  40020b2       55       System.Boolean  1 instance        0 m_UserChangedLimit
79104f64  40020b3       56       System.Boolean  1 instance        1 m_UseNagleAlgorithm
7a772738  40020b4       3c         System.Int32  1 instance        0 m_HostLoopbackGuess
790fed1c  40020b5       40         System.Int32  1 instance       -1 m_ReceiveBufferSize
79104f64  40020b6       57       System.Boolean  1 instance        1 m_Expect100Continue
79104f64  40020b7       58       System.Boolean  1 instance        0 m_Understands100Continue
7a772504  40020b8       59          System.Byte  1 instance        3 m_HttpBehaviour
790fa3e0  40020b9        8        System.String  0 instance 0535b350 m_LookupString
790fed1c  40020ba       44         System.Int32  1 instance        2 m_ConnectionLimit
790fea70  40020bb        c ...ections.Hashtable  0 instance 0535b400 m_ConnectionGroupList
7a746d44  40020bc       10           System.Uri  0 instance 0535b0dc m_Address
790fa3e0  40020bd       14        System.String  0 instance 0535b13c m_Host
790fed1c  40020be       48         System.Int32  1 instance       80 m_Port
7a77a4c4  40020bf       18 ...TimerThread+Queue  0 instance 093325fc m_IdlingQueue
7a77a50c  40020c0       1c ...TimerThread+Timer  0 instance 053c42ac m_ExpiringTimer
79105ef0  40020c1       60      System.DateTime  1 instance 0535b3ec m_IdleSince
790fa3e0  40020c2       20        System.String  0 instance 7a72fa60 m_ConnectionName
790fed1c  40020c3       4c         System.Int32  1 instance        0 m_CurrentConnections
79104f64  40020c4       5a       System.Boolean  1 instance        0 m_HostMode
7a772d88  40020c5       24 ...et.BindIPEndPoint  0 instance 00000000 m_BindIPEndPointDelegate
790f9c18  40020c7       28        System.Object  0 instance 00000000 m_ServerCertificateOrBytes
790f9c18  40020c8       2c        System.Object  0 instance 00000000 m_ClientCertificateOrBytes
790fa3e0  40020c9       30        System.String  0 instance 053622c8 m_HostName
79124228  40020ca       34      System.Object[]  0 instance 0536233c m_IPAddressInfoList
790fed1c  40020cb       50         System.Int32  1 instance        0 m_CurrentAddressInfoIndex
79104f64  40020cc       5b       System.Boolean  1 instance        1 m_ConnectedSinceDns
79104f64  40020cd       5c       System.Boolean  1 instance        0 m_AddressListFailed
79105ef0  40020ce       68      System.DateTime  1 instance 0535b3f4 m_LastDnsResolve
79104f64  40020cf       5d       System.Boolean  1 instance        0 m_IPAddressesAreLoopback
79107d2c  40020c6      7ec System.AsyncCallback  0   shared   static m_ConnectCallbackDelegate
    >> Domain:Value  000de060:NotInit  <<

 

실제 이부분이 설정의 문제인지 .Net Framework의 버그 인지 확인을 위해서 아래의 MSDN 문서를 확인해 본 결과 이는 실제 설계된 동작임을 알 수 있습니다.

즉, IIS Worker Process에서 실행되는 ASP.Net 응용프로그램을 제외한 (즉, W3WP 프로세스 이외에) 모든 프로세스들은 실행 시 autoConfig 설정이 적용용되지 않고, 별도의 설정을 하지 않는 경우 시스템 디폴트 값을 따르게 된다는 것 입니다.

 

ASP.Net 2.0

processModel Element (ASP.NET Settings Schema)
http://msdn.microsoft.com/en-us/library/7w2sway1.aspx

 

 

Attribute

Description

autoConfig

    Specifies whether to automatically configure the following settings to achieve optimal performance based on the machine configuration:

  • The maxWorkerThreads attribute.

  • The maxIoThreads attribute.

  • The minFreeThreads attribute of the httpRuntime element.

  • The minLocalRequestFreeThreads attribute of the httpRuntime element.

  • The maxConnection attribute of the <connectionManagement> Element (Network Settings) element.

    The values are set according to the KB article at http://support.microsoft.com/?id=821268.

    This attribute does not affect the .NET Framework client applications; only ASP.NET applications.

    The autoConfig attribute can be one of the following values.

    Term Definition

    True Indicates that ASP.NET automatically configures the attributes in the preceding list to achieve optimal performance based on the machine configuration.

    False Indicates that ASP.NET should use the explicitly defined values for the attributes in the preceding list.

    The default in the Machine.config file is True, unless there is a previously existing configuration.

 

 

이 포스팅에서 설명하는 문제는 machine.config (또는 DLLHOST.EXE.CONFIG ) 설정을 변경 후 KB821268에서 언급하고 있는 시스템 가이드를 참조하여 변경 한 이후 해결이 되었습니다.

 

이외 비슷하게 ASP.Net 이외에 별도의 프로세스에서 Network에 접근하여 자료를 수집/분석/제공하는 서비스를 이용하는 경우 성능 조정을 위한 파라미터를 설정해 주셔야 합니다.