Tuesday, November 6, 2007

Quick and dirty debugging - DebugView and Trace.WriteLine

Here's another debug scenario for you. After taking great effort in testing your application you hand it off to QA. They throw it back with some interesting bug. Using the exact same steps, you're unable to reproduce on your machine. You have a general idea of where the app is failing, but can't be sure precisely what the issue is.

At this point one usually resorts to some sort of logging. These logging statements are placed in strategic locations through the suspect code (at every other line.) If the bug is in the UI, the common method is MessageBox.Show. If the problem is in an underlying assembly, you must resort to writing output to a text file. The downside is that lots of message boxes wear you out, and it's always a pain tracking down the necessary code to write files.

An easier option is to call Trace.WriteLine (located in System.Diagnostics.) In my sample application (MyApp) I have a single button. Inside the Click event, I add the following line

 Trace.WriteLine("Button1 was clicked");

The event then calls a method in a separate library. In this library method, I've added the following line ('x' was the parameter passed into the method)

 Trace.WriteLine("SomeMethod - Parameter x: " + x.ToString());

When I run the application from VisualStudio and click the button, the Output window contains the trace messages

That's fine if you're running VS, but what about on a QA box? For that I'm using DebugView. After starting up the utility, I fire up the sample application. Click the button (which again calls Trace.Writeline) and DebugView displays the messages previously seen in Visual Studio.

Invalid Data Source crashes Visual Studio

Binding data object to a WinForms control is usually straightforward. Say you have a ComboBox control. Clicking the triangle on the top-right will display the ComboBox Tasks dialog.

Once you check the box to "Use data bound items" you start by selecting the Data Source. Normally, clicking the Data Source dropdown provides you with a list of existing items, as well as the option to create a new one. A few days ago we ran into an issue where, instead of the datasources list, we were given this rather entertaining dialog

With a few hints from the blogging community, we were directed to the Data Sources window (Data > Show Data Sources, or Shift+Alt+D.)

Notice the first entry has an error icon. This is due to a datasource pointing to a non-existent class. Right-click the invalid entry and choose Remove Object. Now the Data Source dropdown behaves as expected.

Thursday, November 1, 2007

Debugging with the Fusion logger

If you've spent much time developing, you've probably run into this scenario. You're working along coding a new application. Everything runs on your machine. Then you hand it off to someone to test (that, or load it on the production server - let the users tell you what's wrong.) Unfortunately, the app crashes as soon as you attempt to start it. Looking in the Event Logs, you see generic .Net errors, but nothing that appears to help. Short of installing VisualStudio on the box in question, how do you track down the issue?

One place to start is the Fusion logs. For this demo, I've created a class library (MyClassLib) and a command-line app (MyConsoleApp.) The app makes a single method call into the library and then exits. Nothing interesting to see when everything works. If I delete MyClassLib.dll and run the application, I witness a rather unpleasant dialog

When an app closes in a violent manner, the first place to look is the computer's event logs. Unfortunately, the only entry for the app looks something like:

"Faulting application myconsoleapp.exe, version, stamp 47293d14, faulting module kernel32.dll, version 5.1.2600.3119, stamp 46239bd5, debug? 0, fault address 0x00012a5b."

So now we turn to the Fusion logs. The first step is to copy the Assembly Binding Log Viewer (fuslogvw.exe) from any machine with VS2005. Start it up; it looks something like this:

Click on the Settings button. In the dialog, select "Log bind failures to disk." Check the box to "Enable custom log path" and specify an already-existing folder (the app won't create it for you.)

Note: According to official documentation, you should be able to use the default log directory. In my experience, that never seemed to work.

With the logger set up I again attempt to run the application. Which again crashes. Going back to the Fusion log viewer, click Refresh. I now have a single entry

Clicking on the entry loads the details in Internet Explorer (shown below.) If you look halfway down the log, you'll see the reference to MyClassLib. Near the end, you'll see the various locations it searched for the file. Now it's a simple matter of finding a copy of my dll and placing in the search path.

*** Assembly Binder Log Entry (10/31/2007 @ 10:14:45 PM) ***

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\testcode\MyConsoleApp\bin\Release\MyConsoleApp.exe
--- A detailed error log follows.

=== Pre-bind state information ===
LOG: User = SH\pgoins
LOG: DisplayName = MyClassLib, Version=, Culture=neutral, PublicKeyToken=null
LOG: Appbase = file:///C:/temp/testcode/MyConsoleApp/bin/Release/
LOG: Initial PrivatePath = NULL
LOG: Dynamic Base = NULL
LOG: Cache Base = NULL
LOG: AppName = MyConsoleApp.exe
Calling assembly : MyConsoleApp, Version=, 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/testcode/MyConsoleApp/bin/Release/MyClassLib.DLL.
LOG: Attempting download of new URL file:///C:/temp/testcode/MyConsoleApp/bin/Release/MyClassLib/MyClassLib.DLL.
LOG: Attempting download of new URL file:///C:/temp/testcode/MyConsoleApp/bin/Release/MyClassLib.EXE.
LOG: Attempting download of new URL file:///C:/temp/testcode/MyConsoleApp/bin/Release/MyClassLib/MyClassLib.EXE.

LOG: All probing URLs attempted and failed.