B# .NET Blog

A faulty application

Right, let's create a plain simple demo to illustrate the principle. It's so simple it fits in one console window using "copy con" file generation:

The code is:

foo.cs (compile using csc /t:library foo.cs)
public class Foo
{
}

bar.cs (compile using csc /t:library /r:foo.dll bar.cs)
class Bar
{
   public static void Main()
   {
      new Foo();
   }
}

Now you should have two assemblies: foo.dll and bar.exe. Run the application, it should just run (although it doesn't do anything useful, it doesn't produce any errors either).

Time has come to make the app faulty. Create a subfolder called "oops" and move the foo.dll file to it. Now bar.exe will fail:

And guess what, you shouldn't even read my blog to find out what's wrong. The runtime is so kind to tell you to enable Fusion:

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

Setting up Fusion

Redundant info maybe, but here are two ways to enable Fusion.

For modern developers - PowerShell

PS C:\Users\Bart> new-itemproperty -path HKLM:\SOFTWARE\Microsoft\Fusion -n EnableLog -t Dword -va 1

PSPath       : Microsoft.PowerShell.Core\Registry::HKEY_LOCAL_MACHINE\SOFTWARE\               Microsoft\Fusion
PSParentPath : Microsoft.PowerShell.Core\Registry::HKEY_LOCAL_MACHINE\SOFTWARE\               Microsoft
PSChildName  : Fusion
PSDrive      : HKLM
PSProvider   : Microsoft.PowerShell.Core\Registry
EnableLog    : 1

For command-line freaks - reg.exe

C:\temp>reg add HKLM\Software\Microsoft\Fusion /v EnableLog /t REG_DWORD /d 1
The operation completed successfully.

For UI lovers - regedit.exe

You should be able to find out yourself :-).

Analyzing the problem

Run bar.exe again after you've enabled Fusion. This time you get a realm of information:

The most interesting portion is the last part:

LOG: Attempting download of new URL file:///C:/temp/foo.DLL.
LOG: Attempting download of new URL file:///C:/temp/foo/foo.DLL.
LOG: Attempting download of new URL file:///C:/temp/foo.EXE.
LOG: Attempting download of new URL file:///C:/temp/foo/foo.EXE.

These are the locations where the system attempted to find the referenced assembly "foo". The "oops" folder isn't there obviously, so the probing operation fails.

Now run fuslogvw.exe and you should see the following log information:

If you double-click on the last line, you'll see the following in a browser window:

*** Assembly Binder Log Entry  (12/10/2006 @ 12:16:56) ***

The operation failed.
Bind result: hr = 0x80070002. The system cannot find the file specified.

Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework\v2.0.50727\mscorwks.dll
Running under executable  C:\temp\bar.exe
--- A detailed error log follows.

=== Pre-bind state information ===
LOG: User = Bart-PC\Bart
LOG: DisplayName = foo, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null
(Fully-specified)
LOG: Appbase = file:///C:/temp/
LOG: Initial PrivatePath = NULL
LOG: Dynamic Base = NULL
LOG: Cache Base = NULL
LOG: AppName = bar.exe
Calling assembly : bar, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null.
===
LOG: This bind starts in default load context.
LOG: No application configuration file found.
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework\v2.0.50727\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:/temp/foo.DLL.
LOG: Attempting download of new URL file:///C:/temp/foo/foo.DLL.
LOG: Attempting download of new URL file:///C:/temp/foo.EXE.
LOG: Attempting download of new URL file:///C:/temp/foo/foo.EXE.
LOG: All probing URLs attempted and failed.

Since there's no application configuration file to specify probing locations, the default probing process is used, effectively looking in the same folder as the application (see Appbase) and in a subfolder with the assembly name (without the extension, i.e. Appbase\AssemblyName, in our example c:\temp\foo). All logs end up in the IE temporary files cache, but you can override this in fuslogvw (or by setting registry entries):

where "c:\temp" is set in the LogPath REG_SZ value in the Fusion registry key. The logging info will end up in a subfolder called "NativeImage":

Setting a custom probing path

You can drive the probing mechanism by specifying probing paths in a configuration file. So create the following bar.exe.config file in the bar.exe folder (c:\temp on my system):

<?xml version="1.0"?>
<configuration>
   <runtime>
      <assemblyBinding xmlns="urn:schemas-microsoft-com:asm.v1">
         <probing privatePath="oops" />
      </assemblyBinding>
   </runtime>
</configuration>

Now bar.exe works fine again:

If you configure Fusion to log all binds to disk, like this:

you'll see log entries appear after re-running the bar.exe applicatin again:

This time with the following logging info:

*** Assembly Binder Log Entry  (12/10/2006 @ 13:01:05) ***

The operation was successful.
Bind result: hr = 0x0. The operation completed successfully.

Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework\v2.0.50727\mscorwks.dll
Running under executable  C:\temp\bar.exe
--- A detailed error log follows.

=== Pre-bind state information ===
LOG: User = Bart-PC\Bart
LOG: DisplayName = foo, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null
(Fully-specified)
LOG: Appbase = file:///C:/temp/
LOG: Initial PrivatePath = NULL
LOG: Dynamic Base = NULL
LOG: Cache Base = NULL
LOG: AppName = bar.exe
Calling assembly : bar, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null.
===
LOG: This bind starts in default load context.
LOG: Private path hint found in configuration file: oops.
LOG: Using application configuration file: C:\temp\bar.exe.config
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework\v2.0.50727\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:/temp/foo.DLL.
LOG: Attempting download of new URL file:///C:/temp/foo/foo.DLL.
LOG: Attempting download of new URL file:///C:/temp/oops/foo.DLL.
LOG: Assembly download was successful. Attempting setup of file: C:\temp\oops\foo.dll
LOG: Entering run-from-source setup phase.
LOG: Assembly Name is: foo, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null
LOG: Binding succeeds. Returns assembly from C:\temp\oops\foo.dll.
LOG: Assembly is loaded in default load context.

As you can see, the oops path is being probed and the assembly is found thanks to our "private path hint" in the configuration file.

Conclusion

Once the FileNotFoundExceptin might have been your worst nightmare (actually MissingMethodException should deserve that spot) but when things get bad, Fusion comes to the rescue. Happy probing!