I worked on a very strange issue that was hard to nail down. My customer had deployed his ASP.NET 2.0 application on 4 IIS 6.0 web servers. The application worked fine on all of them but one. Let's call the servers S1,S2,S3 and S4. The average response times to requests are between 1-3 seconds on S1,S2 and S3 but greater than 45 seconds on S4. It didn't make sense as all the 4 servers were identical in configuration and the same application was running on them.
Since it is the same ASP.NET application that is deployed on all servers, you would be led to believe that the slow response has to be due to some kind of configuration issue on S4, but this was not true as all servers were identical. So what could it be?? 
To isolate the problem,I deployed a test ASP.NET application on S1,S2,S3 and S4 and the response times were identical for any requests to the test application across all four servers. So the next step was to figure out what the customers application is doing. I reproduced the issue on S4 and took a few manual hang dumps using DebugDiag.
Looking at the hang dump in windbg
0:026> !aspxpages
Going to dump the HttpContexts found in the heap.
HttpContext Timeout Completed Running ThreadId ReturnCode Verb RequestPath+QueryString
0x01b771d8 110 Sec yes XXX 302 POST /EnterpriseApplication/login.aspx
0x05ccc41c 110 Sec no 46 Sec XXX 200 GET /EnterpriseApplication/ABC.EnterpriseCatalog/default.aspx
Total 2 HttpContext objects
Thread 26 is running GET /EnterpriseApplication/ABC.EnterpriseCatalog/default.aspx for over 45 seconds.
Looking at the native stack
0:026> kL 200
ChildEBP RetAddr
0e82c1b4 7c822124 ntdll!KiFastSystemCallRet
0e82c1b8 77e6bad8 ntdll!NtWaitForSingleObject+0xc
0e82c228 73ca64ec kernel32!WaitForSingleObjectEx+0xac
0e82c254 73ca6742 cryptnet!CryptRetrieveObjectByUrlWithTimeout+0x12f
0e82c280 73ca3253 cryptnet!CryptRetrieveObjectByUrlW+0x9b
0e82c2f8 73ca6b26 cryptnet!RetrieveObjectByUrlValidForSubject+0x5b
0e82c348 73ca3568 cryptnet!RetrieveTimeValidObjectByUrl+0xbc
0e82c3b0 73ca37d6 cryptnet!CTVOAgent::GetTimeValidObjectByUrl+0xc2
0e82c460 73ca3673 cryptnet!CTVOAgent::GetTimeValidObject+0x2f1
0e82c490 73ca3136 cryptnet!CrlFromCertGetTimeValidObject+0x2d
0e82c4d4 73ca4ab1 cryptnet!CryptGetTimeValidObject+0x58
0e82c530 73ca284b cryptnet!GetTimeValidCrl+0x1e0
0e82c574 73ca27a9 cryptnet!GetBaseCrl+0x34
0e82c614 761d2a7a cryptnet!MicrosoftCertDllVerifyRevocation+0x128
0e82c6a4 761d25e4 crypt32!VerifyDefaultRevocation+0x1d0
0e82c714 761d2ec0 crypt32!CertVerifyRevocation+0xb7
0e82c794 761d2769 crypt32!CChainPathObject::CalculateRevocationStatus+0x1f2
0e82c7dc 761cbac3 crypt32!CChainPathObject::CalculateAdditionalStatus+0x147
0e82c898 761ccfdd crypt32!CCertChainEngine::CreateChainContextFromPathGraph+0x227
0e82c8c8 761c235a crypt32!CCertChainEngine::GetChainContext+0x44
0e82c8f0 76bb80ff crypt32!CertGetCertificateChain+0x60
0e82c954 76bb66f3 wintrust!_WalkChain+0x1a8
0e82c990 76bb4de1 wintrust!WintrustCertificateTrust+0xb7
0e82ca84 76bb2f5e wintrust!_VerifyTrust+0x144
0e82caa8 64025c5c wintrust!WinVerifyTrust+0x4e
0e82cb4c 7a02a405 mscorsec!GetPublisher+0xe4
0e82cba4 79e9650a mscorwks!PEFile::CheckSecurity+0xaa
0e82cbd0 79e96453 mscorwks!PEAssembly::CheckSecurity+0x3a
0e82cbf8 79ea20f1 mscorwks!PEAssembly::PEAssembly+0x106
0e82ce94 79ea1fd7 mscorwks!PEAssembly::DoOpen+0x103
0e82cf28 79e9ff07 mscorwks!PEAssembly::Open+0x79
0e82d08c 79e93f1f mscorwks!AppDomain::BindAssemblySpec+0x247
0e82d124 79e93df8 mscorwks!PEFile::LoadAssembly+0x95
0e82d1c4 79f20d93 mscorwks!Module::LoadAssembly+0xee
0e82d200 79f1cdda mscorwks!Assembly::FindModuleByTypeRef+0x113
0e82d250 79e7b956 mscorwks!ClassLoader::LoadTypeDefOrRefThrowing+0xfc
0e82d354 79f13114 mscorwks!SigPointer::GetTypeHandleThrowing+0x297
0e82d3fc 79084899 mscorwks!CEEInfo::getFieldType+0x14a
0e82d9c8 790635c3 mscorjit!Compiler::impImportBlockCode+0x3303
0e82da4c 7906355b mscorjit!Compiler::impImportBlock+0x20c
0e82da64 79063494 mscorjit!Compiler::impImport+0xe5
0e82da70 79064e1c mscorjit!Compiler::fgImport+0x20
0e82da7c 790614e6 mscorjit!Compiler::compCompile+0xb
0e82dad4 79061236 mscorjit!Compiler::compCompile+0x2df
0e82db68 7906118c mscorjit!jitNativeCode+0xb8
0e82dba0 79f0f9cf mscorjit!CILJit::compileMethod+0x3d
0e82dc0c 79f0f945 mscorwks!invokeCompileMethodHelper+0x72
0e82dc50 79f0f8da mscorwks!invokeCompileMethod+0x31
0e82dca8 79f0ea33 mscorwks!CallCompileMethodWithSEHWrapper+0x84
0e82e060 79ecbc28 mscorwks!UnsafeJitFunction+0x230
0e82e0a0 79ecb252 mscorwks!MethodDesc::IsVerifiable+0x9f
0e82e0d4 79ecb216 mscorwks!MethodDesc::IsVerifiable+0x32
0e82e140 79061344 mscorwks!CEEInfo::isInstantiationOfVerifiedGeneric+0xf9
0e82e188 79061236 mscorjit!Compiler::compCompile+0xbd
0e82e21c 7906118c mscorjit!jitNativeCode+0xb8
0e82e254 79f0f9cf mscorjit!CILJit::compileMethod+0x3d
0e82e2c0 79f0f945 mscorwks!invokeCompileMethodHelper+0x72
0e82e304 79f0f8da mscorwks!invokeCompileMethod+0x31
0e82e35c 79f0ea33 mscorwks!CallCompileMethodWithSEHWrapper+0x84
0e82e714 79f0e795 mscorwks!UnsafeJitFunction+0x230
0e82e7b8 79e87f52 mscorwks!MethodDesc::MakeJitWorker+0x1c1
0e82e810 79e8809e mscorwks!MethodDesc::DoPrestub+0x486
0e82e860 01921f0e mscorwks!PreStubWorker+0xeb
0e82e8b0 79e7c74b ABC_EnterpriseDirectory_DAL_Services!ABC.EnterpriseDirectory.DAL.Services.UserServiceBase..cctor()+0x23
0e82e8b0 79e7c6cc mscorwks!CallDescrWorker+0x33
0e82e930 79e7c8e1 mscorwks!CallDescrWorkerWithHandler+0xa3
0e82ea74 79e7c783 mscorwks!MethodDesc::CallDescr+0x19c
0e82ea90 79e7c90d mscorwks!MethodDesc::CallTargetWorker+0x1f
0e82eaa4 79e8b983 mscorwks!MethodDescCallSite::CallWithValueTypes_RetArgSlot+0x18
0e82eb7c 79e8b8e6 mscorwks!MethodTable::RunClassInitWorker+0x8b
0e82ec04 79e8b7fa mscorwks!MethodTable::RunClassInitEx+0x11e
0e82f0c8 79e87da6 mscorwks!MethodTable::DoRunClassInitThrowing+0x2f0
0e82f118 79e8809e mscorwks!MethodDesc::DoPrestub+0x115
0e82f168 01921f0e mscorwks!PreStubWorker+0xeb
0e82f180 0e105190 0x1921f0e
01b20e98 0e10513d ABC_EnterpriseDirectory_DAL_Services!ABC.EnterpriseDirectory.DAL.Services.UserService..ctor()+0x18
01b20e98 0e1050cc ABC_EnterpriseDirectory_BusinessEntitiesManager!ABC.EnterpriseDirectory.BusinessEntitiesManager.UserManager..ctor(Int32)+0x35
01b20e98 0e105064 ABC_EnterpriseDirectory_Handlers!ABC.EnterpriseDirectory.Handlers.EnterpriseDirectoryHandler.GetUserDelegateOf(Int32)+0x3c
05d53598 0e1014a1 ABC_Common_UI!ABC.Common.UI.SessionPage.LoadSession50()+0x64
0e82f40c 6613cb50 ABC_Common_UI!ABC.Common.UI.SessionPage.OnLoad(System.EventArgs)+0xa9
0e82f40c 6614e12d System_Web_ni!System.Web.UI.Control.LoadRecursive()+0x30
0e82f40c 6614d8c3 System_Web_ni!System.Web.UI.Page.ProcessRequestMain(Boolean, Boolean)+0x59d
0e82f444 6614d80f System_Web_ni!System.Web.UI.Page.ProcessRequest(Boolean, Boolean)+0x67
0e82f480 6614d72f System_Web_ni!System.Web.UI.Page.ProcessRequest()+0x57
0e82f49c 6614d6c2 System_Web_ni!System.Web.UI.Page.ProcessRequestWithNoAssert(System.Web.HttpContext)+0x13
0e82f49c 0e1046c5 System_Web_ni!System.Web.UI.Page.ProcessRequest(System.Web.HttpContext)+0x32
0e82f4d4 65fe6bfb App_Web_default_aspx_13f83278_oebqbt_p!ASP.ABC_enterprisecatalog_default_aspx.ProcessRequest(System.Web.HttpContext)+0x5
0e82f4d4 65fe3f51 System_Web_ni!System.Web.HttpApplication+CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()+0x167
0e82f510 65fe7733 System_Web_ni!System.Web.HttpApplication.ExecuteStep(IExecutionStep, Boolean ByRef)+0x41
0e82f564 65fccbfe System_Web_ni!System.Web.HttpApplication+ApplicationStepManager.ResumeSteps(System.Exception)+0x1b3
05ccc41c 65fd19c5 System_Web_ni!System.Web.HttpApplication.System.Web.IHttpAsyncHandler.BeginProcessRequest(System.Web.HttpContext, System.AsyncCallback, System.Object)+0x8e
0e82f5b4 65fd16b2 System_Web_ni!System.Web.HttpRuntime.ProcessRequestInternal(System.Web.HttpWorkerRequest)+0x1b5
0e82f630 65fcfa6d System_Web_ni!System.Web.HttpRuntime.ProcessRequestNoDemand(System.Web.HttpWorkerRequest)+0x62
0e82f630 79f047fd System_Web_ni!System.Web.Hosting.ISAPIRuntime.ProcessRequest(IntPtr, Int32)+0xfd
0e82f6e8 79f0462c mscorwks!COMToCLRWorkerBody+0x208
0e82f744 79f044fa mscorwks!COMToCLRWorkerDebuggerWrapper+0x37
0e82f928 01a9a295 mscorwks!COMToCLRWorker+0x52f
0e82f950 6a2aa63f CLRStub[StubLinkStub]@1a9a295
0e82fcb4 6a2aa748 webengine!HttpCompletion::ProcessRequestInManagedCode+0x1cb
0e82fcc4 6a2aa715 webengine!HttpCompletion::ProcessCompletion+0x48
0e82fcdc 79f024cf webengine!CorThreadPoolWorkitemCallback+0x1a
0e82fd28 79f0202a mscorwks!UnManagedPerAppDomainTPCount::DispatchWorkItem+0xb2
0e82fd3c 79f021a0 mscorwks!ThreadpoolMgr::ExecuteWorkRequest+0xaf
0e82fd94 79f95a2e mscorwks!ThreadpoolMgr::WorkerThreadStart+0x223
0e82ffb8 77e6608b mscorwks!Thread::intermediateThreadProc+0x49
0e82ffec 00000000 kernel32!BaseThreadStart+0x34
Looking at the managed stack.
0:026> !clrstack
OS Thread Id: 0x8a4 (26)
ESP EIP
0e82e890 7c82ed54 [PrestubMethodFrame: 0e82e890] ABC.EnterpriseDirectory.DAL.Services.SecurityContext`1[[System.__Canon, mscorlib]]..ctor()
0e82e8a0 0e1051cb ABC.EnterpriseDirectory.DAL.Services.UserServiceBase..cctor()
0e82ec30 79e7c74b [GCFrame: 0e82ec30]
0e82f198 79e7c74b [PrestubMethodFrame: 0e82f198] ABC.EnterpriseDirectory.DAL.Services.UserServiceBase..ctor()
0e82f1a8 0e105190 ABC.EnterpriseDirectory.DAL.Services.UserService..ctor()
0e82f1b0 0e10513d ABC.EnterpriseDirectory.BusinessEntitiesManager.UserManager..ctor(Int32)
0e82f1c4 0e1050cc ABC.EnterpriseDirectory.Handlers.EnterpriseDirectoryHandler.GetUserDelegateOf(Int32)
0e82f1dc 0e105064 ABC.Common.UI.SessionPage.LoadSession50()
0e82f1f0 0e1014a1 ABC.Common.UI.SessionPage.OnLoad(System.EventArgs)
0e82f208 6613cb50 System.Web.UI.Control.LoadRecursive()
0e82f21c 6614e12d System.Web.UI.Page.ProcessRequestMain(Boolean, Boolean)
0e82f418 6614d8c3 System.Web.UI.Page.ProcessRequest(Boolean, Boolean)
0e82f450 6614d80f System.Web.UI.Page.ProcessRequest()
0e82f488 6614d72f System.Web.UI.Page.ProcessRequestWithNoAssert(System.Web.HttpContext)
0e82f490 6614d6c2 System.Web.UI.Page.ProcessRequest(System.Web.HttpContext)
0e82f4a4 0e1046c5 ASP.ABC_enterprisecatalog_default_aspx.ProcessRequest(System.Web.HttpContext)
0e82f4a8 65fe6bfb System.Web.HttpApplication+CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
0e82f4dc 65fe3f51 System.Web.HttpApplication.ExecuteStep(IExecutionStep, Boolean ByRef)
0e82f51c 65fe7733 System.Web.HttpApplication+ApplicationStepManager.ResumeSteps(System.Exception)
0e82f56c 65fccbfe System.Web.HttpApplication.System.Web.IHttpAsyncHandler.BeginProcessRequest(System.Web.HttpContext, System.AsyncCallback, System.Object)
0e82f588 65fd19c5 System.Web.HttpRuntime.ProcessRequestInternal(System.Web.HttpWorkerRequest)
0e82f5bc 65fd16b2 System.Web.HttpRuntime.ProcessRequestNoDemand(System.Web.HttpWorkerRequest)
0e82f5c8 65fcfa6d System.Web.Hosting.ISAPIRuntime.ProcessRequest(IntPtr, Int32)
0e82f7d8 79f047fd [ContextTransitionFrame: 0e82f7d8]
0e82f80c 79f047fd [GCFrame: 0e82f80c]
0e82f968 79f047fd [ComMethodFrame: 0e82f968]
Digging further
0:026> du 01630bc4
01630bc4 "http://crl.microsoft.com/pki/crl"
01630c04 "/products/CodeSignPCA2.crl"
It looks like we are trying to connect to http://crl.microsoft.com/pki/crl/products/CodeSignPCA2.crl
The customer had some code in default.aspx that does some sort of signature verification which leads to a certificate revocation check list and if the CRL is pointing to an outside server or a server where you can’t get to from the IIS server then you will see the delay. We narrowed it down to the code in ABC_EnterpriseDirectory_DAL_Services.dll. The code seems to be doing signature verification for its assemblies. These are Authenticode sign assemblies using a Digital certificate issued by a certificate authority such as VeriSign.
You can also sign an assembly using the Strong Name http://support.microsoft.com/kb/815808 signing technology shipping in the .Net Framework.
When we Authenticode sign the assemblies, the .net security tries to validate the signature/publisher as the publisher is used as an evidence for giving the requested permissions to the assembly. This happens every time, the assembly gets loaded. Therefore, while loading such assemblies, the CLR calls the WinTrust.dlls WinVerifyTrust() function which then follows the same call routine as for the Authenticode signed ActiveX control in IE. As a result, the windows security tries to connect to the certificate vendor url to download the CRL.
0:026> .frame 03
03 0e82c254 73ca6742 cryptnet!CryptRetrieveObjectByUrlWithTimeout+0x12f
0:026> dv
pwszUrl = 0x01630bc4
pszObjectOid = 0x00000002 ""
dwRetrievalFlags = 0x2005
dwTimeout = 0x3a98
ppvObject = 0x0e82c2dc
pAuxInfo = 0x00000000
dwThreadId = 0xe08
hThread = 0x00000000
dwErr = 2
fResult = 8197
hToken = 0x00000000
0:026> ?0x3a98
Evaluate expression: 15000 = 00003a98
dwTimeout is the time allowed to get the certificate, which is 15 seconds and following is the URL.
Thread 33 is waiting for an HTTP reply from the Web site that holds the certificate.
0:033> kbL
ChildEBP RetAddr Args to Child
0f85e084 7c822124 71b23a09 00000960 00000001 ntdll!KiFastSystemCallRet
0f85e088 71b23a09 00000960 00000001 0f85e0b0 ntdll!NtWaitForSingleObject+0xc
0f85e0c4 71b23a52 00000960 0000095c 00000000 mswsock!SockWaitForSingleObject+0x19d
0f85e1b4 71c0470c 00000001 00000000 0f85e22c mswsock!WSPSelect+0x380
0f85e204 4e7de746 00000001 00000000 0f85e22c ws2_32!select+0xb9
0f85ea44 4e7de8a5 0000095c 0f85ea68 4e7d976b winhttp!ICSocket::Connect_Start+0x3a8
0f85ea50 4e7d976b 0f763000 4e7c4b5c 00000000 winhttp!CFsm_SocketConnect::RunSM+0x42
0f85ea68 4e7d9805 0e6d5000 00000000 00000000 winhttp!CFsm::Run+0x20
0f85ea8c 4e7de99b 0f763000 0e740000 0f85eab0 winhttp!DoFsm+0x2a
0f85ea9c 4e7de9b8 0000ea60 00000005 00000020 winhttp!ICSocket::Connect+0x32
0f85eab0 4e7ebc6a 0000ea60 00000005 0000ea60 winhttp!ICSocket::Connect+0x13
0f85eaf8 4e7ebde7 0e6d7280 0f85eb1c 4e7d976b winhttp!HTTP_REQUEST_HANDLE_OBJECT::OpenConnection_Fsm+0x44a
0f85eb04 4e7d976b 0e6d7280 00000000 00000000 winhttp!CFsm_OpenConnection::RunSM+0x37
0f85eb1c 4e7d9805 0e6d5000 00000000 00000000 winhttp!CFsm::Run+0x20
0f85eb40 4e7ebe65 0e6d7280 0e740000 0f85eb78 winhttp!DoFsm+0x2a
0f85eb50 4e7edb71 00000000 00000000 0e6d5000 winhttp!HTTP_REQUEST_HANDLE_OBJECT::OpenConnection+0x2f
0f85eb78 4e7ede6d 0e6d71e0 0f85eb9c 4e7d976b winhttp!HTTP_REQUEST_HANDLE_OBJECT::MakeConnection_Fsm+0x9b
0f85eb84 4e7d976b 0e6d71e0 0e740000 00000000 winhttp!CFsm_MakeConnection::RunSM+0x37
0f85eb9c 4e7d9805 0e6d5000 00000000 00000000 winhttp!CFsm::Run+0x20
0f85ebc0 4e7ec68f 0e6d71e0 0e6d5000 0e6d7140 winhttp!DoFsm+0x2a
0f85ebf8 4e7ec8b9 0e6d7140 0f85ec1c 4e7d976b winhttp!HTTP_REQUEST_HANDLE_OBJECT::SendRequest_Fsm+0x8e
0f85ec04 4e7d976b 0e6d7140 0e740000 00000000 winhttp!CFsm_SendRequest::RunSM+0x37
0f85ec1c 4e7d9805 0e6d5000 00000000 00000000 winhttp!CFsm::Run+0x20
0f85ec40 4e7e779c 0e6d7140 0e6d5000 0f761000 winhttp!DoFsm+0x2a
0f85ec60 4e7e7d11 00000000 0f85ec84 4e7d976b winhttp!HTTP_REQUEST_HANDLE_OBJECT::HttpSendRequest_Start+0x2a4
0f85ec6c 4e7d976b 0f761000 00000001 00000000 winhttp!CFsm_HttpSendRequest::RunSM+0x4c
0f85ec84 4e7d9902 0e6d5000 00000000 00000000 winhttp!CFsm::Run+0x20
0f85eccc 4e7d0528 0f761000 0e740000 00000000 winhttp!StartFsmChain+0xd9
0f85ed10 4e7d087e 0e740000 00000000 00000000 winhttp!HttpWrapSendRequest+0x199
0f85ed94 73cac488 0e740000 00000000 00000000 winhttp!WinHttpSendRequest+0x1ee
0f85fe10 73cac916 0e6d1000 0e740000 0e4502c4 cryptnet!InetSendAuthenticatedRequestAndReceiveResponse+0x108
0f85feb4 73cacbb2 0e6d1000 0e4502c4 00002005 cryptnet!InetSendReceiveUrlRequest+0x1b0
0f85fee4 73ca3026 0e4502c4 00000002 00002005 cryptnet!CInetSynchronousRetriever::RetrieveObjectByUrl+0x59
0f85ff20 73ca2e08 0e4502c4 00000002 00002005 cryptnet!InetRetrieveEncodedObject+0x66
0f85ff74 73ca62a0 0e4502c4 00000002 00002005 cryptnet!CObjectRetrievalManager::RetrieveObjectByUrl+0xb1
0f85ffb8 77e6608b 0e450280 00000000 00000000 cryptnet!CryptRetrieveObjectByUrlWithTimeoutThreadProc+0x56
0f85ffec 00000000 73ca6207 0e450280 00000000 kernel32!BaseThreadStart+0x34
We figured out that the server S4 did not have Internet connectivity and hence there was this delay for the very first request where the code was trying to get to the URL http://crl.microsoft.com/pki/crl/products/CodeSignPCA2.crlget .
Some things to consider is if Authenticode signing is really required. As for .net assemblies, you can use strong naming, if strong name suffices your security need then it’s better to stick to strong naming. In case it is required, catalog singing is the better choice. In catalog singing, you will Authenticode sign the complete deployment package/cab file which contains all assemblies. The individual assemblies will only be strong named. Basically Authenticode singing is meant for the code download scenarios.
The other way to work around this problem is to disable the CRL check. This can be done by calling WintrustSetRegPolicyFlags() API. But this will disable the CRL check system wide. Once the assemblies are loaded, you can again call WintrustSetRegPolicyFlags() API to reset the CRL checking. Again, this all will have to be done by the vendor or whoever owns the code.
You could see significant delay if the IIS server does not have Internet connectivity. In our case this was the problem.
Until next time,
HTH,
Vignesh