Monday, October 23, 2006 12:28 PM bart

Assembly probing, Fusion and fuslogvw in 5 minutes

Introduction

A couple of days ago I received the following mail: 

Hi Bart,

I’m trying to add an install functionally that will just basically copy the whole CD content to a local C drive folder. Executing the launcher.exe in that local folder works fine but if I create a desktop shortcut that targets the launcher.exe produced a file not found error for cassinilight.dll. I was wondering if you have an idea in what location was the application looking for cassinilight.dll.  Any help is highly appreciated.

The short answer is really short: probing. Probing is the technique employed by the CLR's assembly loader to find a dependent assembly based on searching for it in various folders. Strongly named assemblies (those you signed using an sn.exe generated public/private key pair) are being searched for in the GAC (and paths specified in codeBase configuration elements, see further; and the "standard locations"). Weakly named assemblies are also probed, by looking in the same folder as the application and in subfolders named after the dependent assemblies themselves. However, sometimes it's not that easy and you really want to see what's going on (a common problem is an assembly being loaded from the GAC while you have recompiled it to your bin\Debug folder in Visual Studio which leads to unexpected debugging results).

In this post, I'm showing you how to make a jumpstart with Fusion, assembly probing and the "Fusion log viewer" aka fuslogvw.exe. For the record, Fusion is the codename of the assembly loader component of the CLR which (you can still see this in the SSCLI source tree under sscli20\clr\src\fusion).

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!

kick it on DotNetKicks.com

Del.icio.us | Digg It | Technorati | Blinklist | Furl | reddit | DotNetKicks

Filed under:

Comments

# dew

Tuesday, March 31, 2009 2:14 AM by DotNetKicks.com

You've been kicked (a good thing) - Trackback from DotNetKicks.com

# Resolving assembly bind failures on a server

Sunday, January 02, 2011 4:27 AM by Rory Primrose

Resolving assembly bind failures on a server

# Sharepoint–File Not Found

Sunday, January 09, 2011 8:28 AM by Khurram Aziz

If you have created your custom ASPX and getting “File Not Found” exception; here are few possible reasons

# FUSLOGVW, Assembly Binding Log Viewer &laquo; El TecnoBa??l de Kiquenet

Pingback from  FUSLOGVW, Assembly Binding Log Viewer &laquo; El TecnoBa??l de Kiquenet

# Custom AppDomain and PrivateBinPath - Programmers Goodies

Pingback from  Custom AppDomain and PrivateBinPath - Programmers Goodies

# .NET Fusion Log Viewer 101 &laquo; LP on .NET

Tuesday, August 02, 2011 6:16 PM by .NET Fusion Log Viewer 101 « LP on .NET

Pingback from  .NET Fusion Log Viewer 101 &laquo; LP on .NET