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.
Comments
- Anonymous
October 23, 2013
Can you not cure this by putting an assemblyRedirect tag in your web/app.config?Thanks,O