Web Role with MVC4 Just Recycles on Windows Azure

   Web Role with MVC4 Just Recycles on Windows Azure 

I was recently working on a customer issue where the WebRole won’t come up. On the Windows Azure Management Portal all that can be seen is that the role keeps on recycling.

The following message is perpetually displayed.

  “Recycling (Recovering role…System is initializing.[2012-12-26T10:56:45Z]”

On the new HTML portal it will look something as below.

 

 

 

So let me explain it with a bit of architecture thrown in. Below is the diagram (shamelessly plagiarized from Kevin Willamson’s blog ) of the workflow of a service getting up and running. I would highly recommend it to be read and understood. 

So let me explain it with a bit of architecture thrown in. Below is the diagram of the workflow of a service getting up and running.

 

 

 

                         (Courtesy : Kevin Williamson Senior Escalation Engineer, Windows Azure )

 

 The yellow part is more or less the Virtual Machine getting prepped and ready to host. That is successful since the VM itself is up and we can remote in to it. So let’s see which of the downstream processes is causing the issue. I used Process Explorer to go through the same and please have the architecture diagram handy to understand the flow of events.

In Process Explorer I see WaHostBootStrapper Starting

 

 Then Vanishing

 

 So now I had to be more attentive to the chain of events. This time I fixated my eyes like an eagle on the events showing up in Process Explorer.

AppAgent Starts HostBootStrapper which in turn starts the following

a)       Diagnostic Agent

b)      Remote Desktop Agent

c)       WaIISHost

 

 

WaIISHost comes up for a fraction of a second and then vanishes (yes it’s just a fraction and I had to attempt 20 screenshots to capture it L).

 

 

And then back to the original state

 

So it’s pretty evident that the WaIISHost crashes which in turn leads to the crash of the WaHostBootstrapper. The WaAppAgent spawns the  WaHostBootstrapper again  and this chain of events keep on repeating.

WaIISHost.exe is the host process for role entry point code for web roles using Full IIS.  This process will load the first DLL found which implements the RoleEntryPoint class (this DLL is defined in E:\__entrypoint.txt) and execute the code from this class (OnStart, Run, OnStop).  Any RoleEnvironment events (ie. StatusCheck, Changed, etc) created in the RoleEntryPoint class will be raised in this process.

The next logical step was to look at Windows Event viewer since it was a process crash.

Sure enough EventViewer showed that WaHostBootstrapper.exe is crashing regularly. It had repeated entries for the following.

Faulting application name: WaHostBootstrapper.exe, version: 6.0.6002.18488, time stamp: 0x505cf7da

Faulting module name: ntdll.dll, version: 6.2.9200.16420, time stamp: 0x505ab405

Exception code: 0xc0000005

Fault offset: 0x0000000000005d92

Faulting process id: 0xd1c

Faulting application start time: 0x01cde9c3f32de167

Faulting application path: E:\base\x64\WaHostBootstrapper.exe

Faulting module path: D:\Windows\SYSTEM32\ntdll.dll

Report Id: 38954d59-55b7-11e2-93ed-00155d36a55b

Faulting package full name:

Faulting package-relative application ID:   

 

Using Process Explorer I was able to see that WaHostBootstrapper.exe is calling WaIISHost.exe so I attached a debugger to WaIISHost.exe to find the cause of the process crash.

 I saw the following first chance exception being generated.

  CLR exception type: System.Reflection.ReflectionTypeLoadException

"Unable to load one or more of the requested types. Retrieve the LoaderExceptions property for more information."

Microsoft.WindowsAzure.ServiceRuntime Critical: 201 : ModLoad: 000007fc`906a0000 000007fc`907a9000 D:\Windows\Microsoft.NET\Framework64\v4.0.30319\diasymreader.dll

Role entrypoint could not be created:

System.TypeLoadException: Unable to load the role entry point due to the following exceptions:

-- System.IO.FileLoadException: Could not load file or assembly 'System.Web.Mvc, Version=3.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35' or one of its dependencies. The located assembly's manifest definition does not match the assembly reference. (Exception from HRESULT: 0x80131040)File name: 'System.Web.Mvc, Version=3.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35'

WRN: Assembly binding logging is turned OFF.

To enable assembly bind failure logging, set the registry value [HKLM\Software\Microsoft\Fusion!EnableLog] (DWORD) to 1.

Note: There is some performance penalty associated with assembly bind failure logging.

To turn this feature off, remove the registry value [HKLM\Software\Microsoft\Fusion!EnableLog].

---> System.Reflection.ReflectionTypeLoadException: Unable to load one or more of the requested types. Retrieve the LoaderExceptions property for more information.

at System.Reflection.RuntimeModule.GetTypes(RuntimeModule module)

at System.Reflection.RuntimeModule.GetTypes()

at System.Reflection.Assembly.GetTypes()

at Microsoft.WindowsAzure.ServiceRuntime.RoleEnvironment.GetRoleEntryPoint(Assembly entryPointAssembly)

--- End of inner exception stack trace ---

at Microsoft.WindowsAzure.ServiceRuntime.RoleEnvironment.GetRoleEntryPoint(Assembly entryPointAssembly)

at Microsoft.WindowsAzure.ServiceRuntime.RoleEnvironment.CreateRoleEntryPoint(RoleType roleTypeEnum)

at Microsoft.WindowsAzure.ServiceRuntime.RoleEnvironment.InitializeRoleInternal(RoleType roleTypeEnum)

ModLoad: 000007fc`a2f00000 000007fc`a2f96000 D:\Windows\SYSTEM32\clbcatq.dll

ntdll!ZwTerminateProcess+0xa:

000007fc`a2fa2eaa c3 ret

 

Subsequently we end up with the following exception.

 Exception object: 00000000017e0070

Exception type: System.TypeLoadException

Message: Unable to load the role entry point due to the following exceptions:

-- System.IO.FileLoadException: Could not load file or assembly 'System.Web.Mvc, Version=3.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35' or one of its dependencies. The located assembly's manifest definition does not match the assembly reference. (Exception from HRESULT: 0x80131040)

File name: 'System.Web.Mvc, Version=3.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35'

 

WRN: Assembly binding logging is turned OFF.

To enable assembly bind failure logging, set the registry value [HKLM\Software\Microsoft\Fusion!EnableLog] (DWORD) to 1.

Note: There is some performance penalty associated with assembly bind failure logging.

To turn this feature off, remove the registry value [HKLM\Software\Microsoft\Fusion!EnableLog].

InnerException: System.Reflection.ReflectionTypeLoadException, Use !PrintException 00000000017dcf08 to see more.

StackTrace (generated):

<none>

StackTraceString: <none>

HResult: 80131522

I checked the version of System.Web.Mvc copied to the site root is 4.0.20710.0 while the failure is due to the non-availability of System.Web.Mvc version 3.0.0.0

#. In the Web.Config I also see the following entry so it’s set correctly.

     <assemblies>

        <add assembly="System.Web.Abstractions, Version=4.0.0.0, Culture=neutral, PublicKeyToken=31BF3856AD364E35" />

        <add assembly="System.Web.Helpers, Version=2.0.0.0, Culture=neutral, PublicKeyToken=31BF3856AD364E35" />

        <add assembly="System.Web.Routing, Version=4.0.0.0, Culture=neutral, PublicKeyToken=31BF3856AD364E35" />

        <add assembly="System.Web.Mvc, Version=4.0.0.0, Culture=neutral, PublicKeyToken=31BF3856AD364E35" />

        <add assembly="System.Web.WebPages, Version=2.0.0.0, Culture=neutral, PublicKeyToken=31BF3856AD364E35" />

        <add assembly="System.Data.Entity, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089" />

 </assemblies>

 

#. I dumped the version from debugger and it also show 4.0

  

#. I dumped the version from debugger and it also show 4.0

System_Web_Mvc

         start end module name

    00000000`1dab0000 00000000`1db30000 System_Web_Mvc (deferred)            

    Image path: E:\approot\bin\System.Web.Mvc.dll

    Image name: System.Web.Mvc.dll

    Using CLR debugging support for all symbols

    Has CLR image header, track-debug-data flag not set

    Timestamp: Wed Jul 11 04:47:13 2012 (4FFD0551)

    CheckSum: 00085F6D

    ImageSize: 00080000

    File version: 4.0.20710.0

    Product version: 4.0.20710.0

    File flags: 0 (Mask 3F)

    File OS: 4 Unknown Win32

    File type: 2.0 Dll

    File date: 00000000.00000000

    Translations: 0000.04b0

    CompanyName: Microsoft Corporation

    ProductName: Microsoft ASP.NET MVC

    InternalName: System.Web.Mvc.dll

    OriginalFilename: System.Web.Mvc.dll

    ProductVersion: 4.0.20710.0

    FileVersion: 4.0.20710.0

    FileDescription: System.Web.Mvc.dll

    LegalCopyright: © Microsoft Corporation. All rights reserved.

    Comments: System.Web.Mvc.dll

So I started looking at the modules which seemed related to MVC or seemed like User Interface related dlls. I saw  and dumped the following dlls.  

 

                    T4MVCExtensions

    start end module name

    00000000`01070000 00000000`0107c000 T4MVCExtensions (deferred)            

    Image path: E:\approot\bin\T4MVCExtensions.dll

    Image name: T4MVCExtensions.dll

    Using CLR debugging support for all symbols

    Has CLR image header, track-debug-data flag not set

    Timestamp: Tue Dec 11 18:56:20 2012 (50C781D4)

    CheckSum: 00000000

    ImageSize: 0000C000

    File version: 3.0.0.0

    Product version: 3.0.0.0

    File flags: 0 (Mask 3F)

    File OS: 4 Unknown Win32

    File type: 2.0 Dll

    File date: 00000000.00000000

    Translations: 0000.04b0

    CompanyName: David Ebbo

    ProductName: T4MVCExtensions

    InternalName: T4MVCExtensions.dll

    OriginalFilename: T4MVCExtensions.dll

    ProductVersion: 3.0.0.0

    FileVersion: 3.0.0.0

    FileDescription: T4MVCExtensions

    LegalCopyright: Copyright © 2012

    Comments: Runtime helpers used by code generated by T4MVC

#. I found this is some extension downloaded from Nugethttps://nuget.org/packages/T4MVCExtensions/3.0.0

#. While System.Web.Mvc 4.0 dll is referred in the project directly, the project also leverages some 3rd party dlls like T4MVCExtensions.dll , MvcSiteMapProvider.dll and  DoodleReport.Web.

To prove it conclusively I loaded the dlls in a code decompile tool called reflector (you may use your favorite one). To my amusement all these were using System.Web.Mvc 3.0 internally.

 

 

 

 

  

 

The reference to these 3rd party components was removed and the role republished.  The WebRole came up and didn’t get stuck in the recycle mode anymore. The components like T4NVC and Doodle chart can be used once they release versions using System.Web.Mvc 4.0 dlls. 

This role had worked previously on Windows 2008R2 with the same references as the .Net framework on it has System.Web.Mvc 3.0.  On Windows 2012 it we don’t have the System.Web.Mvc 3.0.  by default in .Net framework so the 3rd party components were not getting the referenced assembly loaded and were throwing exception.

 

To isolate further we add the components one by one and found that Doddle was the one that requiring a specific version. T4MVC extensions and SiteMap provider seemed to work even though they were 3.0, so it must be the case that it can work as long as the package doesn’t require a specific version of MVC. We obviously had re-direct bindings which allowed anything not requiring a specific MVC version to re-bind to MVC4. Doddle is open source so we re-compiled it to target MVC4 and added it back to the project. Re-deployed the service and now it comes up fine.

The other alternative is to use a use a startup task to add MVC3 to theGAC.  https://blogs.infosupport.com/adding-assemblies-to-the-gac-in-windows-azure/explains the process kind of. That way you could add MVC3 to the GAC for applications that need it. But the intention of the blog was to give an understanding of the process that happens behind the scene.

I hope you enjoyed this rather long blog and it helps resolving some of your role recycling “Recycling (Recovering role…System is initializing” issues.