Interop

Get Seamless .NET Exception Logging From COM Clients Without Modifying Your Code

Matt Adamson

Code download available at:ExceptionLogging.exe(267 KB)

Contents

Why Log .NET Exceptions?
How .NET Exceptions are Currently Logged
Exception Information Lost
Workarounds
Hooking
Concurrency Issues
Exception Queue
Exception Logging Thread
The ExceptionPublisher Class
Fallback Logging
ASP
Sample Project
Conclusion

Many developers who still use ASP pages for presentation services are integrating COM and .NET objects to provide the business services of the application. Using .NET objects from ASP can help developers gain experience with the .NET Framework before migrating to ASP.NET. Their ASP pages make use of the new .NET components through COM-callable wrappers (CCW). But how do they handle exceptions?

Whenever a .NET exception is thrown from .NET components to the ASP page, it's converted into an Err object that contains information on the error. Unfortunately, a wealth of information such as the stack trace, all inner exceptions, and other properties within the .NET exception are lost; only the string description and a number are returned to the ASP page. To allow .NET exceptions thrown to COM clients to be added to the event log, I've written a component that uses techniques such as hooking.

Why Log .NET Exceptions?

Most applications log unexpected exceptions and, in some cases, expected exceptions. The Exception Management Application Block (EMAB) provides a very useful framework for publishing exceptions. You simply call a publish method with the Exception object. This could either be from within a centralized catch handler or from an unhandled exception handler using the UnhandledException event in the AppDomain class (see Figure 1).

Figure 1 Unhandled Exception Handlers

void Start() { AppDomain.CurrentDomain.UnhandledException += new UnhandledExceptionEventHandler(OnAppDomainException); try { ... // perform work of the application } catch(MyApplicationException exception) { ExceptionManager.Publish(exception) } } ... work performed elsewhere in application ... private static void OnAppDomainException( object sender, UnhandledExceptionEventArgs eventArgs) { ExceptionManager.Publish(eventArgs.ExceptionObject); }

Logged exceptions provide a wealth of information when diagnosing problems. For example, if the exception thrown is wrapping another exception, the inner exceptions usually contain a lot of detail to build up the context for the error. The most inner exception usually contains the actual error that caused the failure, such as a database schema that is out of date or a SQL Server™ database that is not available.

Other useful functionality includes the ability to find specific information related to the particular exceptional condition. For example, an ArgumentOutOfRange exception contains the argument value that was invalid.

The runtime's ability to capture a stack trace when an exception is thrown means that you can determine the specific function that failed. For example, if a function such as IsUserInRole fails and can be clearly seen in the call stack, start looking at the user's security rights or security related-code.

Given these advantages, it is therefore valuable to be able to log any .NET exceptions thrown, regardless of whether a .NET or COM client is being used.

How .NET Exceptions are Currently Logged

Most ASP developers use some form of logging component to log errors to a specific destination, such as an event log or flat file. When an error condition occurs, a flag is usually set to indicate the page has failed and that the relevant information should be logged. The only information about the error is present in the Err object. The Err object provides access to a Number and Description property, and the description property contains the most detailed information on the error. Sample ASP code is shown here:

On Error Resume Next Dim oSupplierInvoice Set oSupplierInvoice = Server.CreateObject("ECommerce.SupplierInvoice") oSupplierInvoice.GenerateFromOrder(oPurchaseOrder) If Err.Number <> 0 Then LogPageError "Failed to generate purchase order for supplier invoice, SupplierInvoiceID=" & oSupplierInvoice.ID End If

LogPageError is a fictional method that wraps access to the logging component and adds additional context to the error log, such as the page being called, the user within the session, and the Description and Number from the Err object. If the ECommerce.SupplierInvoice component is written as a COM object, then the description and number will be the only information the component raises, so no information will be lost. However, if the component is written in a .NET language, a CLR exception will have been thrown and converted into an Err object, and much of the useful information in the CLR exception will be lost.

Exception Information Lost

When a COM client uses a .NET component, a COM-callable wrapper is created. The CCW is a proxy to the real .NET object. This object is implemented in either the mscorwks.dll or mscorsvr.dll, depending on factors such as a how many processors the system has or environment variable settings. Either of these DLLs are loaded by mscoree.dll, which acts as a shim to load either of the modules mscorwks or mscorsvr.

When a .NET exception is thrown, the CCW retrieves the .NET exception interface and creates a COM error object based on the information it contains. This error object can typically be queried for the description and the number. The description is taken from the exception's Message property, and the number is taken from the exception's HResult property, if available.

Adam Nathan documented a technique in his excellent book, .NET and COM: The Complete Interoperability Guide (Sams Publishing, 2002) where a .NET exception could be obtained for COM clients by calling GetErrorInfo. This works because the mscorsvr/mscorwks DLL makes a call to SetErrorInfo after the .NET exception is caught within the CCW. This retrieves the last error object set on the current thread. The IErrorInfo interface pointer returned can then be queried for the .NET exception interface _Exception. Here is the C++ code to do this:

try { ... // Work which throws a .NET exception through a CCW } catch(_com_error &err) { _ExceptionPtr spException = err.ErrorInfo(); }

You can see here that the .NET exception is simply retrieved by querying the IErrorInfo pointer set on the current logical thread. Unfortunately, this only works for early-bound clients using the specific interface that is defined for the component. Late-bound scripting clients such as ASP pages always use the IDispatch Invoke method to call methods and properties defined on the .NET component. The Invoke method calls GetErrorInfo to retrieve rich error information in order to set the relevant fields of the EXCEPINFO structure. The scripting engine then uses this structure to build the Err object for the ASP page to query.

Since the GetErrorInfo call also clears the error information, it is not available after the late-bound call completes. If this didn't happen, it would in theory be possible to write a method within another C++ COM server that simply called GetErrorInfo and retrieved the .NET exception interface pointer.

Figure 2** .NET Calls Through a CCW **

To see why the scenario fails for late-bound clients, I'll walk through the calling of a managed method from a late-bound COM client. The .NET method call is initiated through late binding in a script engine (VBScript or JScript®), hosted by asp.dll. This results in IDispatch::Invoke being called on the CCW (an EXCEPINFO structure is passed). Next, the CCW invokes the actual managed method on the managed object. In our scenario, this method throws an exception. The CCW catches the exception and calls SetErrorInfo to store the exception's information. The implementation of IDispatch::Invoke sees that an exception occurred and calls GetErrorInfo to retrieve the info it needs to fill the EXCEPINFO structure. Since GetErrorInfo clears the error information, when IDispatch::Invoke returns, the .NET exception is lost. This process is outlined in Figure 2.

Workarounds

A workaround to enable exceptions to be published is to modify all properties/methods in the managed code component to catch all types of exceptions and publish them before rethrowing:

public void DoSomethingUseful() { try { ... // Do some useful work } catch(Exception exception) { ExceptionManager.Publish(exception); throw; } }

Clearly, this approach has serious drawbacks. There is a significant development overhead: all .NET methods/properties that could be called by COM clients need to be modified to include a catch handler. In practice, this will mean all public methods/properties, as it is impossible to predict the future use of components.

Another problem with this approach is that if the .NET component is being used by a .NET client, this client may also publish the exception, eventually causing the exception to be published twice. This problem also arises if a public method on the component calls another public method on the component.

Furthermore, catching exceptions of type Exception is not considered good practice for various reasons, cited in the exception handling chapter in Jeffrey's Richter's excellent book, Applied Microsoft .NET Framework Programming (Microsoft Press®, 2002). For example, a StackOverFlow exception could be thrown, in which case the catch handler shouldn't do any more work, such as publishing the exception, that could further add to the stack.

Even if these reasons were not enough, sometimes the source code to the .NET components will not be available, as in the case of third party components. The only solution is to implement a .NET proxy for the component, which simply delegates to the object surrounded by a try/catch block.

Now let's look at how to create a component that provides seamless logging of .NET exceptions when they are thrown to COM clients without requiring any modification to .NET components. Any .NET exceptions that are raised to COM clients through the CCW are automatically logged using the EMAB.

Hooking

In Windows®, functions exported by DLLs can be replaced by other custom functions as long as they provide the same signature. This technique is known as hooking. It works by changing function address pointers within a DLL's import address table (IAT). Each imported API has its own reserved place in the IAT where the address of the imported function is written to by the Windows loader. Once a module is loaded, the IAT contains the address that is invoked when calling imported APIs.

My hooking functions are contained in the HookSupport class, available on the MSDN®Magazine Web site as part of the code download associated with this article. The most important method on this class is HookImportFunctionsByName, which takes the module handle in which the import functions will be hooked, the name of the module being hooked, an array of structures containing the function name being hooked, and the new custom function procedure address. John Robbins, the Bugslayer columnist for MSDN Magazine, often showed how to hook functions in the days of Win32®. I am using the techniques John presented in his debugging book, Debugging Applications for Microsoft .NET and Microsoft Windows (Microsoft Press, 2003).

As mentioned earlier, the reason a .NET exception is not available to ASP clients is that it is initially set as the thread's error object using SetErrorInfo; it is later cleared when the scripting runtime calls GetErrorInfo to build the EXCEPINFO structure required for the IDispatch Invoke method. In theory, if the SetErrorInfo function could be hooked and replaced within another custom function, the .NET exception interface pointer could be extracted and published using the EMAB before the scripting runtime calls GetErrorInfo to clear it.

The SetErrorInfo function is defined in the OLEAUT32 module. Unfortunately, although this module is loaded from mscorwks/mscorsvr, it can't be easily hooked because the OLEAUT32 module doesn't exist in the import address table for mscorwks/mscorsvr; rather it only exists in a separate delay-load IAT. This is because the module is delay loaded: at run time, LoadLibrary and GetProcAddress are called to resolve the function address for SetErrorInfo. The resulting address is then stored in the delay-load IAT so that future calls go directly to the API.

Although hooking relies on modifying the import table for the module, for delay loaded DLLs, this must be done before the first call to that function is made inside the module. Since you do not explicitly load mscorwks.dll, you can't be sure that this has not happened already for SetErrorInfo when you start hooking.

The solution requires a variety of functions from different modules to be hooked in turn. First, I set up initial hooks for the LoadLibrary calls from the OLE32 module. When the module mscoree.dll is being loaded by OLE32 in the hook setup, further hooks are set up for the LoadLibrary calls from the mscoree.dll module. When the module mscorwks.dll is being loaded by mscoree.dll in the second hook setup, additional hooks are set up for the GetProcAddress calls from the mscorwks.dll module. (Note that mscorsvr can also be used sometimes, depending on various factors, including number of processors.) With those hooks in place, when a SetErrorInfo call is made by the mscorwks.dll module hooked using GetProcAddress (either by name or ordinal value), the function pointer to my custom SetErrorInfo is returned, which publishes the exception. This is shown in Figure 3.

Figure 3** Various Hooks **

In the LoadLibrary hooked functions for the modules OLE32.dll and mscoree.dll, the Win32 LoadLibrary call is always made first. This ensures that the module request is loaded and available to be used to install further hooks to LoadLibrary and GetProcAddress calls from these modules. The most important issue to address here is to ensure that the hooks are made early enough within the process that hosts the .NET components.

When a .NET exception is thrown and caught by the CCW, the custom defined SetErrorInfo function is called. The .NET interface pointer can then be extracted from this function by querying for the _Exception interface, as shown here:

HRESULT __stdcall SetErrorInfoWithExceptionLogging( DWORD dwReserved, IErrorInfo *pErrInfo) { CComQIPtr<_Exception> spException(pErrInfo); if (spException) { // Perform work with .NET exception interface } }

The calls to the various hooking functions are shown in Figure 4.

Figure 4 Debug Option Showing Hooked Function Calls

Once the functions are hooked they remain hooked until the process terminates. This can cause an access violation if an error is raised within the process after the DLL has been unloaded because the SetErrorInfo hooks are still pointing to functions defined in the DLL which, when unloaded, will point to invalid addresses. To resolve this, the DllCanUnloadNow function returns S_FALSE to prevent the DLL from being unloaded. The alternative approach is to reset the original hooked function pointers. Either approach you choose is fine.

Concurrency Issues

The hooked SetErrorInfoWithExceptionLogging function should be thread-safe. At first, you might want to place .NET object creation and logging in the custom SetErrorInfoWithExceptionLogging function and use a critical section to protect against concurrent access. But consider the following sequence of events. First, Thread A causes an error and enters SetErrorInfoWithExceptionLogging, acquiring a critical section. While Thread A is executing, it tries to acquire another resource held by Thread B, so it waits for this resource to be available. While Thread B holds this resource, it generates an error. The SetErrorInfoWithExceptionLogging function is then called on Thread B, blocking the attempt to acquire the critical section.

Result: deadlock! The code in SetErrorInfoWithExceptionLogging is not directly trying to acquire other resources potentially held by other threads, but if it is required to create .NET objects in it, several events will happen. For example, while creating the .NET object, the system may need to load a DLL. This means obtaining the loader lock for that time interval, which creates the potential for a deadlock. If .NET objects were created and used to publish the exception in the SetErrorInfoWithExceptionLogging, a cross-apartment call would be made from a single-threaded apartment (STA) to a multithreaded apartment (MTA). That could give rise to a reentrant scenario in which SetErrorInfoWithExceptionLogging is called in an STA and the hooked function makes an outgoing COM call to another apartment, which causes the COM libraries to enter the STA message loop. When another COM method call for an object hosted in this STA comes in, it is accepted because we are in the message loop. During the processing of this new request, the SetErrorInfoWithExceptionLogging function is called once again.

Owing to these concurrency issues, the SetErrorInfoWithExceptionLogging function does as little work as possible. It simply adds the exception to a queue that is accessed from the ManagedExceptionLoggerTask worker thread. The ManagedExceptionLoggerTask object performs the logging of the exception, which does the significant work of creating the managed ExceptionPublisher object and publishing the exception. This thread is not subject to the same locking issues, making it a good place in which to publish the exceptions.

Exception Queue

To minimize the blocking issues, a new queue object is created. Managed exceptions are added and removed on a first-in first-out basis. These exceptions will be removed from the queue by another worker thread and then published using the exception management application block.

The type of objects stored within the queue cannot be .NET Exception interface pointers because the exception needs to be accessed across apartments from the worker thread. For example, the custom hooked function could be called on an STA, but the worker thread uses an MTA. In an ASP application, each client will be calling on its own STA.

The global interface table (GIT) stores interface pointers so they can be safely accessed across apartments. Objects added from one apartment can be removed from the GIT and accessed in another apartment. When an interface is added to the GIT, a cookie is returned in a DWORD. This DWORD needs to be stored within the queue so that the worker thread can simply pop the DWORD off the queue and use the GIT to extract the .NET exception object corresponding to this cookie.

The date and time the exception was raised also needs to be recorded within the element in the queue. Consider the following scenario: an error is raised, the custom SetErrorInfo function is called, the exception is added to the queue, and the worker thread is signaled to publish the exception. If the worker thread doesn't get scheduled for some time, even after only a few seconds, other exceptions may get added to the queue before the first is actually published. The actual recorded time in the event log will thus be slightly out of sync with the actual time the error was raised. The recorded time is therefore essential. The recorded time and the .NET exception cookie will be wrapped within a structure, which is added to the queue.

Because the STL queue class is not thread-safe and a small amount of work needs to be done to add an exception to the queue, the ManagedExceptionQueue class was created. This protects simultaneous access to the queue using a class-critical section, it wraps up the use of the GIT into push and pop functions on the class, and provides a nice interface for the worker thread and custom hook function to set and retrieve exception information from the queue. This process is mapped out in Figure 5.

Figure 5** Two Clients Raising Exceptions Through the CCW **

As soon as the custom SetErrorInfo function adds the exception to the queue, an event is signaled within the worker thread to notify it that an exception can be published. The code for the queue class is found in ManagedExceptionQueue.cpp in the download on the MSDN Magazine Web site.

Exception Logging Thread

A new ManagedExceptionLoggerTask class is created to act as a worker thread. This sits idle waiting for either of two events to become signaled: a new exception has been added to the queue or the thread should terminate. The task should usually be asked to finish when the application is closing down.

The new thread is created after the initial hooks have been set up in the Inject method on the ManagedExceptionInjector COM object. If the thread wakes up because another thread has signaled the Exception Added event, then each exception is retrieved from the queue using the ManagedExceptionQueue pop method. This extracts and returns the interface pointer from the GIT using the stored cookie. Each of the exceptions is then published using the ExceptionPublisher class through a CCW. If the exception publishing fails for any reason, an attempt is made to extract useful information from the exception, such as the stack trace and inner exceptions, and to log this to the event log. If this also fails, the exception information is output to the debug window using the OutputDebugString Win32 function. This exception logging process is shown in Figure 6.

Figure 6** Exception Logging Process **

The ManagedExceptionLoggerTask joins an MTA; it performs all the exception publishing in the MTA to avoid cross-apartment calls when the ExceptionPublisher object is created. Managed objects, such as the ExceptionPublisher, that are exposed to COM behave as if they had aggregated the freethreaded marshaler. In other words, they can be called from any COM apartment in a freethreaded manner. The only managed objects that do not exhibit this freethreaded behavior are those objects that derive from ServicedComponent.

An instance of the ExceptionInfo structure is extracted from the top of the queue using the ManagedExceptionQueue pop method. This structure contains the date and time the exception was raised. The date and time is used to create a managed NameValueCollection object with one name value item containing the value of the date. The name of this value is called ExceptionRaisedDateTime; it is only used when displaying the exception in the event log.

The ExceptionPublisher Class

Information in the .NET exception extracted from the hooked SetErrorInfo needs to be logged somewhere, whether in a file, event log, or e-mail message. Specifically, all the information mentioned previously, such as properties of the exception, the stack trace, and any inner exceptions, need to be included in the log.

The Patterns and Practices Group at Microsoft has created the EMAB specifically for this purpose. If you haven't already done so, I strongly suggest you review all other application blocks available to see if they are appropriate to use within your current projects. The exception block is a simple and flexible mechanism for publishing exception information through an ExceptionManager class. It also allows you to create your own publishers to publish data to other data sources such as XML files or a database.

The Publish method in this class needs to be called to publish the exception. This is defined as static, which makes it easy for .NET clients to use; however, it isn't friendly for COM clients, which can't call static methods. A simple solution is to use the facade pattern to wrap access to the class within another class. There are various guidelines developers should adhere to in order to make .NET components easier for COM clients to use. One is to ensure that the class has a default constructor. Two new assemblies were created, which contain the ExceptionPublisher class and IExceptionPublisher interface. The wrapper method within the class is shown in the following code:

public void Publish(Exception exception, NameValueCollection nameValueItems) { ExceptionManager.Publish(exception, nameValueItems); }

The overloaded Publish method is called, which takes not only the exception object but also a collection of name-value items that can specify other important data when the exception is published. The ManagedExceptionLoggerTask worker thread uses this to add the date and time the exception was raised.

The ExceptionPublisher class also employs a number of other best-practice techniques. This includes using explicit GUIDs for the class and interface, and deriving from a custom interface rather than using the default class interface. To learn more about these techniques, take a look at .NET and COM: The Complete Interoperability Guide. By providing a default constructor and a public non-static method to publish exceptions, I've created an easy way for COM clients to use my class to publish exceptions:

IExceptionPublisherPtr spExceptionPublisher(__uuidof(ExceptionPublisher)); spExceptionPublisher->Publish(spException, spNameValueItems);

Fallback Logging

If the .NET exception cannot be published using the exception block (for reasons such as failure to create the object or inadequate permissions), an attempt should be made to log to the event log directly. If this also fails, the exception should be written to the debug window as a last resort. Interestingly, if the ExceptionPublisher's Publish method fails, two exceptions have to be logged to the event log. The first is the .NET exception raised from the Publish method that contains information on why the Publish method failed, and the second is the actual exception being logged.

The first exception can actually be extracted using Adam Nathan's technique presented in the beginning of this article because an early-bound COM client is being used here to call a .NET component. The .NET exception is extracted directly from the error object by querying for the _Exception interface.

The exception information is added to the event log in the CManagedExceptionLoggerTask::LogExceptionToEventLog method. This method does work in a manner similar to the Publish method, extracting all inner exceptions and writing out a stack trace for each exception. If any errors happen to occur with this logging to the event log, the reason and the exception information are written to the debug window.

ASP

ASP applications usually run in either the dllhost or inetinfo process, depending on the isolation level. For example, medium (which is unavailable on Windows NT®) and high use dllhost.exe, while low always uses inetinfo. Each ASP application using the ManagedExceptionInjector component must not only create the object and call Inject but also store a reference to it within the Application variable. Here is the ASP code to do this, with error handling omitted for brevity:

Dim oInjector Set oInjector = Server.CreateObject( "NetInteropServicesEngine.ManagedExceptionInjector") Set Application("ManagedInjector") = oInjector

The call to inject all the required hooks within the process needs to be called within the application OnStart event. This ensures that it is called before any other clients in the process cause SetErrorInfo to be called on a CCW; otherwise, the hooks can't be set up. This call should be placed right at the beginning of this event handler before any other code.

Storing the object in the application variable allows us to access it in the application On End event and then call the UnInject method. The object must be apartment-agile. In other words, it must be accessible from any apartment within the process to be able to be stored in the application variable. To do this, the object aggregates the freethreaded marshaler using the CoCreateFreeThreadedMarshaler function.

The application On End event will be called when the Web application ends, either because the Web server has been restarted or the specific application has been unloaded (this is only available to applications running with high isolation). The UnInject method simply signals to the ManagedExceptionLoggerTask worker thread to finish and clean up.

Sample Project

A sample Web project called ManagedExceptionWebApp is available for download from the MSDN Magazine Web site. A main page provides hyperlinks to three other pages. One simply displays text, another adds a couple of numbers together, and a final page calls a .NET object called PurchaseOrder in the MSDN.ExceptionGenerator namespace, which always throws a .NET exception.

In the ThrowNetException ASP page, a managed PurchaseOrder object is created and the GenerateOrderForSupplier method is called. The code for this method is shown in Figure 7. This sample follows a common design pattern: using data access classes to access the data store while leaving the business object responsible for the functions of the business objects.

Figure 7 GenerateOrderForSupplier

public void GenerateOrderForSupplier(String supplierName) { try { PurchaseOrderData purchaseOrderData = new PurchaseOrderData(); purchaseOrderData.GenerateOrderForSupplier(supplierName); } catch(SqlException exception) { throw new PurchaseOrderException(String.Format( "Failed to generate purchase order for supplier {0}", supplierName), exception); } }

PurchaseOrderData GenerateOrderForSupplier attempts to log onto a database using a connection that is obviously incorrect, as you can see in the following code snippet:

public void GenerateOrderForSupplier(String supplierName) { using(SqlConnection connection = new SqlConnection( ConfigurationSettings.AppSettings["connStr")) { connection.Open(); ... // Code to insert purchase order details into database } }

When a SqlException is thrown from the PurchaseOrderData GenerateOrderForSupplier method, it is caught in the PurchaseOrder GenerateOrderForSupplier method. The exception is then thrown again using the custom exception type PurchaseOrderException. This type is used for all exceptions when processing purchase orders. It derives from BaseException, which is a requirement for all exception classes created for use in the EMAB.

To run the Web application, it needs to be installed in a new virtual directory called ManagedExceptionWebApp. The .NET assemblies need to be built, copied into the application folder and registered for COM interop using regasm. The exception block assemblies Microsoft.ApplicationBlocks.ExceptionManagement.dll and Microsoft.ApplicationBlocks.ExceptionManagement.Interfaces.dll also need to copied to this folder. (Note that the Microsoft.ApplicationBlocks.ExceptionManager.dll assembly needs to be installed using the InstallUtil utility to register a number of different event sources before it's used from an ASP page. If this doesn't get run, the ASP application will attempt to create the event sources the first time they're referenced and can, in some configurations, cause a security exception because the anonymous user doesn't have permissions to create event sources. A file called RegisterTypeLibs copies the assemblies from the debug folder and registers them for COM interop.

The application folder for the CLR host where the .NET components are created will be either <windows>\system32 when dllhost is used for applications with protection set to medium or high, and <windows>\system32\inetsrv for applications with low protection. The corresponding configuration files will therefore be called dllhost.exe.config and inetinfo.exe.config if any runtime configuration is required.

Conclusion

In this article I've discussed the design and implementation of an object that intercepts the .NET runtime CCW calls when exceptions are raised. This serves up seamless exception logging without any changes to .NET components. I have also examined various issues I encountered trying to build a robust solution which works well in a production environment.

Not only does the Framework show you a variety of low-level techniques such as hooking and dispatching work to a queue, but it does so by building a useful component which you can put to good use straightaway in your own applications.

Matt Adamson is a senior software engineer at Tranmit plc where he designs and develops n-tier applications using C# and C++. You can reach him at adamson_matthew@hotmail.com.