Custom IIdentity serialization issue

Posted on July 16, 2015 in dotnet , umbraco and edited on July 17, 2015

I am spending a fair amount of time these days figuring out what happens when an Umbraco AppDomain restarts, and troubleshooting some bad situations that we have seen where Umbraco locks itself, would not restart, could use all the CPU, etc.

In order to cause some restarts, I invoke HttpRuntime.UnloadAppDomain() from some views that I reach via JMeter. That has always worked. And then, suddenly, it has decided to throw an exception:

[SerializationException: Type is not resolved for member 'Umbraco.Core.Security.UmbracoBackOfficeIdentity,Umbraco.Core, Version=1.0.5662.30061, Culture=neutral, PublicKeyToken=null'.]
   System.Web.Hosting.ApplicationManager.HostingEnvironmentShutdownInitiated(String appId, HostingEnvironment env) +0
   System.Web.Hosting.HostingEnvironment.RemoveThisAppDomainFromAppManagerTableOnce() +160
   System.Web.Hosting.HostingEnvironment.InitiateShutdownInternal() +393
   System.Web.HttpRuntime.ShutdownAppDomain(String stackTrace) +530
   System.Web.HttpRuntime.UnloadAppDomain() +97
   ASP._Page_Views_Whatever_Index_cshtml.Execute() in d:\Umbraco\src\Umbraco.Web.UI\Views\Whatever\Index.cshtml:32

It is not something absolutely new, come to think of it. There are a few reports of similar errors on Our and elsewhere on the 'net. And I could not get rid of it. Enabling Fusion log (run tool FUSLOGVW.exe from C:\Program Files (x86)\Microsoft SDKs\Windows\v8.1A\bin\NETFX 4.5.1 Tools) gives us the following log entry¹:

*** Assembly Binder Log Entry  (03/07/2015 @ 17:56:19) ***

The operation failed.
Bind result: hr = 0x80070002. Le fichier spécifié est introuvable.

Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
Running under executable  c:\windows\system32\inetsrv\w3wp.exe
--- A detailed error log follows. 

=== Pre-bind state information ===
LOG: DisplayName = Umbraco.Core, Version=1.0.5662.30061, Culture=neutral, PublicKeyToken=null
 (Fully-specified)
LOG: Appbase = file:///c:/windows/system32/inetsrv/
LOG: Initial PrivatePath = NULL
LOG: Dynamic Base = NULL
LOG: Cache Base = NULL
LOG: AppName = w3wp.exe
Calling assembly : (Unknown).
===
LOG: This bind starts in default load context.
LOG: No application configuration file found.
LOG: Using host configuration file: C:\Windows\Microsoft.NET\Framework64\v4.0.30319\aspnet.config
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework64\v4.0.30319\config\machine.config.
LOG: Policy not being applied to reference at this time (private, custom, partial, or location-based assembly bind).
LOG: Attempting download of new URL file:///c:/windows/system32/inetsrv/Umbraco.Core.DLL.
LOG: Attempting download of new URL file:///c:/windows/system32/inetsrv/Umbraco.Core/Umbraco.Core.DLL.
LOG: Attempting download of new URL file:///c:/windows/system32/inetsrv/Umbraco.Core.EXE.
LOG: Attempting download of new URL file:///c:/windows/system32/inetsrv/Umbraco.Core/Umbraco.Core.EXE.
LOG: All probing URLs attempted and failed.

It is just not looking at all into the application ~/bin directory. The log entries list looks like:

See, the error comes from w3wp.exe itself and not application d526b26e, which would have been the actual web application AppDomain, and was able to load the dll:

*** Entrée du journal Binder d'assembly  (03/07/2015 @ 17:55:58) ***

L'opération a réussi.
Résultat de liaison : hr = 0x0. L’opération a réussi.

Gestionnaire des assemblys chargé à partir de :  C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
Exécution sous l'exécutable  c:\windows\system32\inetsrv\w3wp.exe
--- Un journal des erreurs détaillé suit. 

=== Informations d'état de liaison préalable ===
JRN : DisplayName = Umbraco.Core, Version=1.0.5662.30061, Culture=neutral, PublicKeyToken=null
 (Fully-specified)
JRN : Appbase = file:///D:/TEMP/u7.2/src/Umbraco.Web.UI/
JRN : PrivatePath initial = D:\TEMP\u7.2\src\Umbraco.Web.UI\bin
JRN : base dynamique = C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Temporary ASP.NET Files\root\9ad6511c
JRN : base de cache = C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Temporary ASP.NET Files\root\9ad6511c
JRN : AppName = d526b26e
Assembly appelant : (Unknown).
===
JRN : cette liaison démarre dans le contexte de chargement de default.
JRN : utilisation du fichier de configuration de l'application : D:\TEMP\u7.2\src\Umbraco.Web.UI\web.config
JRN : utilisation du fichier de configuration d'hôte : C:\Windows\Microsoft.NET\Framework64\v4.0.30319\aspnet.config
JRN : utilisation du fichier de configuration de l'ordinateur à partir de C:\Windows\Microsoft.NET\Framework64\v4.0.30319\config\machine.config.
JRN : stratégie non appliquée à la référence à ce stade (liaison d'assembly privée, personnalisée, partielle ou basée sur l'emplacement).
JRN : tentative de téléchargement de la nouvelle URL file:///C:/Windows/Microsoft.NET/Framework64/v4.0.30319/Temporary ASP.NET Files/root/9ad6511c/d526b26e/Umbraco.Core.DLL.
JRN : tentative de téléchargement de la nouvelle URL file:///C:/Windows/Microsoft.NET/Framework64/v4.0.30319/Temporary ASP.NET Files/root/9ad6511c/d526b26e/Umbraco.Core/Umbraco.Core.DLL.
JRN : tentative de téléchargement de la nouvelle URL file:///D:/TEMP/u7.2/src/Umbraco.Web.UI/bin/Umbraco.Core.DLL.
JRN : le téléchargement de l'assembly a réussi. Tentative d'installation du fichier : D:\TEMP\u7.2\src\Umbraco.Web.UI\bin\Umbraco.Core.dll
JRN : entrée dans la phase d'installation du cache de téléchargement.
JRN : le nom de l'assembly est : Umbraco.Core, Version=1.0.5662.30061, Culture=neutral, PublicKeyToken=null
JRN : la liaison a réussi. Elle retourne un assembly à partir de C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Temporary ASP.NET Files\root\9ad6511c\d526b26e\assembly\dl3\1a177545\e070c6cf_a6b5d001\Umbraco.Core.dll.
JRN : l'assembly est chargé dans le contexte de chargement default.

It really looks like the custom identity is leaking out of the ASP.NET site AppDomain and into the main w3wp.exe AppDomain, which has no way to deal with it. As soon as I log out of the back-office, and there is no identity anymore, the problem vanishes. Log back in, and the problem comes back. This old blog post somehow explains it, but... 2006?! Other posts (eg that one) propose solutions... that do not work.

Solutions?

• w3wp.exe should be able to find the assembly
• Custom identity should inherit MarshalByRefObject
• Custom identity should serialize itself to generic identity
• Avoid custom identities

We do not want w3wp.exe to find the assembly because then it would load that assembly into the main AppDomain and never release it.

The Umbraco UmbracoBackOfficeIdentity already inherits from ASP.NET FormsIdentity so it cannot also inherit from MarshalByRefObject, so let us say this is not an option.

As to serializing to a generic identity... first, I have not been able to get it to work properly, and second, there are reports on the 'net of identities being serialized to, and from w3wp.exe, and then Umbraco would get a generic identity back instead of the expected UmbracoBackOfficeIdentity.

Following some of the discussions... the logical conclusion would be to not use custom identities at all. Just implement all the custom parts as extension methods over a generic identity. However... as soon as you register a custom claim in the generic ClaimsIdentity, it will be serialized, and cause an error.

Workaround

At that point I stopped trying to understand, and looked for a workaround. There is one, and it is quite simple: just make sure there is no current identity when restarting. My restart code now looks like (this is in a controller):

HttpContext.User = null;
System.Web.HttpContext.Current.User = null;
Thread.CurrentPrincipal = null;            
HttpRuntime.UnloadAppDomain();

And the issue is gone.

But I still have absolutely no idea what is going on.

Edit 07/17

My friend and distinguished MVP Shannon has put together a simple MVC app that does not depend on Umbraco at all, and reproduces the issue. On the first restart attempt, an exception is thrown. You can download it here.