Thursday, November 6, 2014

How to Prevent FaultException<TDetail> From Eating Your Stack Trace

Eating 
Any action that is performed by the CRM SDK that results in an exception on the CRM server, is returned as a System.ServiceModel.FaultException<Microsoft.Xrm.Sdk.OrganizationServiceFault> exception.  The interesting problem that this creates, is the FaultException<TDetail> exception class overrides the ToString() method of the Exception class, eating the entire stack trace.  So given the following hypothetical program:
public void Test()
{
    using (var service = GetOrganizationServiceProxy())
    {
        try
        {
            return service.GetEntity<SystemUser>(Guid.NewGuid());
        }
        catch (FaultException<OrganizationServiceFault> ex)
        {
            Log(ex);
            throw;
        }
    }
}

The log would only contain the following text:


System.ServiceModel.FaultException`1[Microsoft.Xrm.Sdk.OrganizationServiceFault]: systemuser With Id = f483d6ed-ed8c-4d5d-b6e4-145e8d8ec993 Does Not Exist (Fault Detail is equal to Microsoft.Xrm.Sdk.OrganizationServiceFault).

Which doesn’t contain the stack trace at all. For a simple program like this, it’s pretty easy to figure out where the exception occurred, but in an enterprise level application with hundreds or thousands of sdk calls, it becomes nearly impossible. After looking at the base Microsoft Exception class implementation I came up with the FullStackTraceException class:

/// <summary>
/// Provides a method for handling any exception types that "eat" the stacktrace in it's implementation of ToString()
/// </summary>
[Serializable]
public class FullStackTraceException : Exception
{
    private readonly Exception _exception;

    private FullStackTraceException(Exception ex)
    {
        _exception = ex;
    }

    public static Exception Create(Exception exception)
    {
        return CreateInternal((dynamic)exception);
    }

    private static Exception CreateInternal(Exception exception)
    {
        return exception;
    }

    public static FullStackTraceException Create<TDetail>(FaultException<TDetail> exception)
    {
        return new FullStackTraceException(exception);
    }

    private static FullStackTraceException CreateInternal<TDetail>(FaultException<TDetail> exception)
    {
        return new FullStackTraceException(exception);
    }

    public override String ToString()
    {
        String s = _exception.ToString();

        if (_exception.InnerException != null)
        {
            s = String.Format("{0} ---> {1}{2}   --- End of inner exception stack trace ---{2}", s, _exception.InnerException, Environment.NewLine);
        }

        string stackTrace = _exception.StackTrace;
        if (stackTrace != null)
        {
            s += Environment.NewLine + stackTrace;
        }

        return s;
    }
}



It uses static factories to determine if the exception is of the FaultException<TDetail> type or not.  If it isn’t, the exception is returned unchanged.  If it is, a new version of FullStackTraceException is returned, with an overridden ToString method that includes the stack trace as it would normally appear.  So if the first example was changed to:


public void Test()
{
    using (var service = GetOrganizationServiceProxy())
    {
        try
        {
            return service.GetEntity<SystemUser>(Guid.NewGuid());
        }
        catch (FaultException<OrganizationServiceFault> ex)
        {
            Log(FullStackTraceException.Create(ex));
            throw;
        }
    }
}

The ToString() call in Log would return


System.ServiceModel.FaultException`1[Microsoft.Xrm.Sdk.OrganizationServiceFault]: systemuser With Id = f483d6ed-ed8c-4d5d-b6e4-145e8d8ec993 Does Not Exist (Fault Detail is equal to Microsoft.Xrm.Sdk.OrganizationServiceFault).

Server stack trace:
   at System.ServiceModel.Channels.ServiceChannel.HandleReply(ProxyOperationRuntime operation, ProxyRpc& rpc)
   at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout)
   at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation)
   at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)


Exception rethrown at [0]:
   at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
   at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
   at Microsoft.Xrm.Sdk.IOrganizationService.Retrieve(String entityName, Guid id, ColumnSet columnSet)
   at Microsoft.Xrm.Sdk.Client.OrganizationServiceProxy.RetrieveCore(String entityName, Guid id, ColumnSet columnSet)
   at Microsoft.Xrm.Sdk.Client.OrganizationServiceProxy.Retrieve(String entityName, Guid id, ColumnSet columnSet)
   at DLaB.Utilities.ClientSideOrganizationService.Retrieve(String entityName, Guid id, ColumnSet columnSet) in c:\TFS\DLaB.Utilities\ClientSideOrganizationService.cs:line 88
   at DLaB.Extensions.GetEntity[T](IOrganizationService service, Guid id, ColumnSet columnSet) in c:\TFS\DLaB.Extensions.cs:line 1214
   at DLaB.Extensions.GetEntity[T](IOrganizationService service, Guid id) in c:\TFS\DLaB.Extensions.cs:line 1185
   at DLaB.Example.Test() in c:\TFS\Example.cs:line 7

Which includes the appropriate client side stack trace, allowing for much simpler debugging!  (In actual use, the FullStackTraceException.Create(ex) would occur in the Log method itself to keep the code DRY.)



Enjoy!