Troubleshooting dependency resolution problems using Process Monitor

Unhandled Exception: System.IO.FileNotFoundException: Could not load file or assembly 'NativeLibWrapper.dll' or one of its dependencies. The specified module could not be found.  at MainApp.Program.Main(String[] args)

The error above is possibly one of the most searched .Net exceptions on Google. Could not load file or assembly exceptions occur when Windows is not able to load a dll needed by the calling code. There are numerous reasons why the loader can fail to load the required DLLs, such as a missing dependency, calling code that does not have permission to read the needed DLL, etc.

Dependency Walker and Fusion Log Viewer are common tools used to troubleshoot missing dependency problems. Dependency Walker statically resolves all the DLLs needed by a native PE file and flags missing dependencies, while Fusion Log Viewer catches assembly binding problems in managed code during runtime. Both are great tools, and do their respective jobs well, but they fall short with applications that dynamically load native dlls or contain both native and managed assemblies. In this blog post I’ll discuss how we can use Process Monitor to do exploratory debugging on “Could not load file or assembly” problems, as well as how this process can be automated.

The Problem

Process Monitor is an easy to use real-time event monitoring tool for Windows that shows you file system, registry, network, process and thread activity log. To demonstrate how we can use Process Monitor for troubleshooting, I created a managed application called MainApp.exe. MainApp references a managed wrapper library called NativeWrapper.dll, which references a native C++ dll called NativeLib.dll. (You can download the complete solution from github here). To simulate a missing dependency, let's delete NativeLib.dll. Executing MainApp.exe now will result in the following error:

>MainApp.exe
Unhandled Exception: System.IO.FileNotFoundException: Could not load file or assembly 'NativeLibWrapper.dll' or one of its dependencies. 
  The specified module could not be found. at MainApp.Program.Main(String[] args)

Notice that the exception didn’t mention the actual missing dependency, it only pointed out that one of the NativeLibWrapper.dll dependencies is missing, but which one? It’s easy to figure out the problem in this toy application due to it's small scope. However, in real world applications where each assembly can have dozens of dependencies scattered around the system, this can become a nightmare. As I mentioned above, Dependency Walker does not work with managed assemblies, so it won’t be helpful. NativeLib.dll is an unmanaged DLL, so Fusion Log Viewer won’t detect it. Lets see how we can troubleshoot this problem using Process Monitor.

Run Process Monitor and monitor MainApp.exe

• Run Process Monitor and start capturing events.
• Add a Process Name filter for MainApp.exe to limit the displayed events to those related to MainApp only (This keeps the logs from becoming unmanageably large). 
• Run MainApp.exe after the capture begins 
• Once you get the FileNotFoundException, switch to Process Monitor and stop capturing events (File > Capture Events).

Manual Log analysis using Process Monitor

Now we can analyze the logs. The exception that we're looking at is a file not found exception, which is almost certainly related to a file system event. So, we know we can filter out everything other than file system events. You can do this by turning the process, registry and network buttons off in the toolbar. The process monitor window should now look something like this: 

Let’s trim the irrelevant events:

1. We are trying to find problems related to a DLL, so exclude all events that are not related to DLL files.
2. Since we are interested in finding out whether the file was successfully loaded or not, let’s exclude events where the result is not one of the following: NAME NOT FOUND, PATH NOT FOUND, ACCESS DENIED, FILE LOCKED WITH ONLY READERS and SUCCESS. Process Monitor does not allow you to add OR filters so you will have to add exclude filters for all the results not in the above list.
3. CreateFile and CreateFileMapping operations are triggered when Windows tries to load a DLL, so exclude all other operations. I had to exclude events where the operation was BUFFER OVERFLOW, FILE LOCKED WITH ONLY READERS and Query*. Depending upon your process, you might have to exclude a few other operations as well.

The following snapshot displays all the filters I had to apply for the above to take effect.

Now it’s time for all the hard work to pay off. Scroll down to the bottom of the log and try to find the file that the loader was not able to find (i.e. there is not an event with Result = SUCCESS for it). It should be fairly easy to spot, since most of the time it will be the entry with tons of contiguous NAME NOT FOUND results. For my demo app, visual inspection clearly reveals that the loader was not able to find NativeLib.dll.

Automatic Log Analysis using Dependz

Now, this explorative process is a lot of fun for the first few times, but it loses its charm pretty quickly. To make it less tedious I automated the analysis part of the process. Rather than manually filtering and inspecting the logs, I wrote a small tool called Dependz to analyze the log file and list all the unresolved dependencies. You can download Dependz’s source here and binary here. 

Dependz will need a Process Monitor log file (in xml format) along with the name of the application to analyze as inputs, as shown below: 

Let’s analyze the NativeLib.dll problem with Dependz this time. Go to Process Monitor and reset all the filters we just applied (Ctrl + L > Reset) then save the log in xml format. 

Run Dependz.exe with the required inputs as shown below: 

Hooray! Dependz figured out that NativeLib.dll was missing and also listed all the paths probed by the loader while trying to find it. Besides NativeLib.dll, a few other DLLs like rpcss.dll and mscorrc.dll were not found, but I think these libraries are optional and didn't cause this problem. I usually work my way from the bottom to the top of the log. I've found that the last logged dll is almost always the cause of the problem. 

Permissions related problems

Dependz can also help you figure out dependency errors because of insufficient permissions. Assume that a user without read permissions to NativeLib.dll runs MainApp.exe, and MainApp.exe crashes with the following exception:

>MainApp.exe
Unhandled Exception: System.IO.FileLoadException: Could not load file or assembly
at MainApp.Program.Main(String[] args)

This exception is not helpful, as expected. Fire Process Monitor, capture logs and run Dependz with it. 

This worked! Dependz figured out that MainApp.exe was not able to load NativeLib.dll because access was denied to the file and also revealed the actual path from where MainApp.exe was trying to load NativeLib.dll.

Dependz is a work in progress. As I encounter more scenarios where I can automate Process Monitor log analysis, I'll add more functionality. If you have any particular troubleshooting scenarios that you frequently repeat with Process Monitor, please leave a comment and I’ll try to help.