Issues while migration of website from .Net Framework 3.5 to .Net Framework 4.0 with Web Server on .Net Framework 4.5

  • Article

Irfan Ahmed, Senior Support Escalation Engineer, brings to us another solution to a unique problem, while working with one of his customers.

I have come across this issue where customer has migrated his website from .NET Framework 3.5 to .NET Framework 4.0 and the Web server has .NET Framework 4.5. 1 installed. The web application faces intermittently hangs. During our troubleshooting and different dump analysis we found that the process is hung due to a deadlock scenario between two threads. 

Dump analysis on the Hang dump taken

 0:046> kL 

# ChildEBP RetAddr 

00 01d1ef70 77928e44 ntdll!ZwWaitForSingleObject

01 01d1efd4 77928d28 ntdll!RtlpWaitOnCriticalSection

02 01d1effc 7405bf8f ntdll!RtlEnterCriticalSection

03 (Inline) -------- clr!UnsafeEnterCriticalSection

04 01d1f010 73fb3b2f clr!CrstBase::SpinEnter

05 01d1f030 740a7337 clr!CrstBase::Enter

06 (Inline) -------- clr!CrstBase::AcquireLock

07 (Inline) -------- clr!CrstBase::CrstHolder::{ctor

08 01d1f0d0 73fd4a5b clr!ClassLoader::LoadTypeHandleForTypeKey_Body

09 01d1f114 73fd56ca clr!ClassLoader::LoadTypeHandleForTypeKey

0a 01d1f19c 73fd1ca7 clr!ClassLoader::LoadTypeDefThrowing

0b 01d1f210 73fc23a2 clr!ClassLoader::LoadTypeDefOrRefThrowing

0c 01d1f2c8 73fc599b clr!SigPointer::GetTypeHandleThrowing

0d 01d1f3a4 73fd2f90 clr!SigPointer::GetTypeHandleThrowing

      0e 01d1f3e4 73fffd83 clr!ClassLoader::LoadTypeDefOrRefOrSpecThrowing

 0:046> .frame 0n4;dv /t /v

04 01d1f010 73fb3b2f clr!CrstBase::SpinEnter  

@esi              class CrstBase * this = 0x1ebff438

@ebx              unsigned long iter = 0xa

@edi              unsigned long i = 0

<unavailable>     int delayCount = <value unavailable>

 

0:046> dt _RTL_CRITICAL_SECTION  0x1ebff438

w3wp!_RTL_CRITICAL_SECTION

   +0x000 DebugInfo        : 0x1ec36c38 _RTL_CRITICAL_SECTION_DEBUG

   +0x004 LockCount        : 0n-14

   +0x008 RecursionCount   : 0n1

   +0x00c OwningThread     : 0x000023d0 Void      >> thread 47

   +0x010 LockSemaphore    : 0x00000f20 Void

               +0x014 SpinCount        : 0

 This is how 47 looks like

0:047> kL

# ChildEBP RetAddr 

00 1dddd3f0 77928e44 ntdll!ZwWaitForSingleObject

01 1dddd454 77928d28 ntdll!RtlpWaitOnCriticalSection

02 1dddd47c 7405bf8f ntdll!RtlEnterCriticalSection

03 (Inline) -------- clr!UnsafeEnterCriticalSection

04 1dddd490 73fb3b2f clr!CrstBase::SpinEnter

05 1dddd4b0 740a7337 clr!CrstBase::Enter

06 (Inline) -------- clr!CrstBase::AcquireLock

07 (Inline) -------- clr!CrstBase::CrstHolder::{ctor

08 1dddd550 73fd4a5b clr!ClassLoader::LoadTypeHandleForTypeKey_Body

09 1dddd594 73fd56ca clr!ClassLoader::LoadTypeHandleForTypeKey

0a 1dddd61c 73fd1ca7 clr!ClassLoader::LoadTypeDefThrowing

0b 1dddd690 73febfc9 clr!ClassLoader::LoadTypeDefOrRefThrowing

0c 1dddd6e0 73feab99 clr!ClassLoader::LoadApproxTypeThrowing

0d 1dddd714 73fe7ae7 clr!ClassLoader::LoadApproxParentThrowing

0e 1dddd8c4 73fd8330 clr!ClassLoader::CreateTypeHandleForTypeDefThrowing

 0:047> dt this 0x1ecd5878

Local var @ esi Type CrstBase*

  +0x000 m_criticalsection : _RTL_CRITICAL_SECTION

   +0x000 m_pHostCrst      : 0x028714c8 IHostCrst

   +0x018 m_dwFlags        : 0xc0000023

 

0:047> dt _RTL_CRITICAL_SECTION  0x1ecd5878

w3wp!_RTL_CRITICAL_SECTION

   +0x000 DebugInfo        : 0x028714c8 _RTL_CRITICAL_SECTION_DEBUG

   +0x004 LockCount        : 0n-10

   +0x008 RecursionCount   : 0n1

   +0x00c OwningThread     : 0x00001e20 Void   >> thread 46

   +0x010 LockSemaphore    : 0x00000f1c Void

   +0x014 SpinCount        : 0

 One of the waiting thread

 0:320> kM10

# ChildEBP RetAddr 

00 3fe5d690 77928e44 ntdll!ZwWaitForSingleObject

01 3fe5d6f4 77928d28 ntdll!RtlpWaitOnCriticalSection

02 3fe5d71c 7405bf8f ntdll!RtlEnterCriticalSection

03 (Inline) -------- clr!UnsafeEnterCriticalSection+0x7

04 3fe5d730 73fb3b2f clr!CrstBase::SpinEnter

05 3fe5d754 73fc7e99 clr!CrstBase::Enter

06 (Inline) -------- clr!ListLockEntry::FinishDeadlockAwareEnter

07 3fe5d784 73fe38a5 clr!ListLockEntry::LockHolder::DeadlockAwareAcquire

08 3fe5d85c 73ff1ebe clr!MethodDesc::MakeJitWorker

09 3fe5d8d0 73fc50f6 clr!MethodDesc::DoPrestub

0a 3fe5d938 73fb42b9 clr!PreStubWorker

0b 3fe5d968 23b36012 clr!ThePreStub

This has been found as bug and has been fixed in the latest release of CLR. The other work around for .NET 4.0 , 4.5.1 and 4.5.2 is to disable profileGuidedOptimizations. This is a new feature added in .NET 4.5. this workaround may add fractional increase in the startup time.

Written by: Irfan Ahmed, Senior Support Escalation Engineer, EMEA/INDIA Team

Reviewed by: Rachan Rosario, Escalation Engineer