Thursday, February 19, 2015

Avoiding exception wrapping and exposing Exception.Data via log4net.

In .NET exception handling is often a layered approach involving several classes and methods catching a specific exception and then throwing a new exception with some additional details and the original exception wrapped as the inner exception. The additional details are often useful, but after passing through several layers of try-catch-throw-new-exception the root exception can become obscured somewhere down the stack trace and inner exceptions.

A common methods exception might be something like:

public string Foo(string someInput)
{
    try 
    {
        doSomethingWithTheInput(someInput);
    }
    catch(Exception ex)
    {
         throw new FooIsBrokenException("Foo is bad for: " + someInput, ex);
    }
    finally 
    {
        // Common cleanup code to release any resources etc...
    }
}

If the exception is going to be exposed outside the current project then the wrapping exception will likely be useful. However, if it is only going to be for internal use as a way of adding additional context to the base exception you can save some effort by using Exception.Data.

public string Foo(string someInput)
{
    try 
    {
        doSomethingWithTheInput(someInput);
    }
    catch(Exception ex)
    {
        // Consider what to do if the key is already present.
        ex.Data.Add("someInput", someInput);
        throw;
    }
    finally 
    {
        // Common cleanup code to release any resources etc...
    }
}

log4net

Now you've got the details in the Data dictionary they need to be exposed. I'm working on an older project that started in 2007 and uses log4net. There is a suggestion on Logging Exception.Data using Log4Net to use a custom PatternLayoutConverter on each layout appender to convert the data dictionary.

I've gone with a slightly different approach by registering an IObjectRenderer with log4net you can append the additional Exception.Data values. The advantage here is that it will work with all the appenders to render exceptions.

public class ExceptionObjectLogger : IObjectRenderer
{
    public void RenderObject(RendererMap rendererMap, object obj, TextWriter writer)
    {
        var ex = obj as Exception;

        if (ex == null)
        {
            // Shouldn't happen if only configured for the System.Exception type.
            rendererMap.DefaultRenderer.RenderObject(rendererMap, obj, writer);
        }
        else
        {
            while (ex != null)
            {
                rendererMap.DefaultRenderer.RenderObject(rendererMap, obj, writer);
                RenderExceptionData(rendererMap, ex, writer);
                ex = ex.InnerException;
            }
        }
    }

    private void RenderExceptionData(RendererMap rendererMap, Exception ex, TextWriter writer)
    {
        foreach (DictionaryEntry entry in ex.Data)
        {
            if (entry.Key is string)
            {
                writer.Write(entry.Key);
            }
            else
            {
                IObjectRenderer keyRenderer = rendererMap.Get(entry.Key.GetType());
                keyRenderer.RenderObject(rendererMap, entry.Key, writer);
            }

            writer.Write(": ");

            if (entry.Value is string)
            {
                writer.Write(entry.Value);
            }
            else
            {
                IObjectRenderer valueRenderer = rendererMap.Get(entry.Value.GetType());
                valueRenderer.RenderObject(rendererMap, entry.Value, writer);
            }
            writer.WriteLine();
        }
    }
}

Logging configuration additions. Note that it only applies to classes inheriting from Exception.


    ...
    
    ...

See also:

Tuesday, February 17, 2015

Troubleshooting Salesforces Trialheads execution of Developer Edition org code

I thought I'd knock out a quick Trialhead challenge to see what was involved.

When checking the challenge Manipulating Records with DML I was surprised that my apex class failed with the message:

Challenge not yet complete... here's what's wrong:
Executing the 'insertNewAccount' method failed. Either the method does not exist, is not static, or does not insert the proper account.

I was reasonably confident my Apex class was correct.

I'm not going to post my class here, as that seems to go against the concept of Trialhead if you could just Google for an answer. Rather, I found something interesting when trying to figure out what was wrong.

Trialhead is using executeAnonymous via the tooling API to examine the apex class in my developer edition org.

It appears to take a black box approach to confirming that the Apex class is behaving as expected. If the method can be invoked and satisfy the given assertions it passes the challenge.

If you just open up the log in the developer console you can see the assertions being made, and in my case that the test was failing due to a STORAGE_LIMIT_EXCEEDED DmlException. So I can delete some records, free up some space and get the challenge to pass.

Better yet, if you open the RAW Log you can extract the anonymous Apex that is being used to test the code. Note that the default developer console log viewer won't show the executed code or logging levels like the FuseIT SFDC Explorer does.

Execute Anonymous: Account a = AccountHandler.insertNewAccount('My Test Account'); System.assertNotEquals(a,null); if(a != null) {delete a;}

Once you know this, you can more accurately figure out why your Apex class might be failing. For example, imagine you had implemented a check in your Org to ensure the Account Name is unique. If there was already an Account with the Name 'My Test Account' (maybe from a previous run that partially failed) that this would show up in the debug log. The debug log could provide some good clues for failures. The FuseIT SFDC Explorer will show the debug log directly with the anonymous apex.

In theory there is nothing stopping you implementing the minimal code to pass the assertions being made by the anonymous Apex. For example, with the above anonymous Apex, as long as insertNewAccount returns a non-null Account that can be deleted here the test will pass. Currently no check is made that the returned account has the correct name or was indeed inserted as part of the test. Have I gained anything here? Probably not, the goal with Trialhead is to learn about an aspect of Salesforce rather than game the system to earn a badge on your profile. Chances are that if you can figure out a way to work around the assertions you are also more than capable of completing the actual challenge.

I should note that a challenge may make multiple anonymous apex calls. Salesforce may also change the assertions made for each challenge at any time.


Historically interesting footnote

The following was true when I was originally going to post this last week. After contacting Salesforce about the issue they have subsequently resolved it. At the time the anonymous apex appeared as:

Execute Anonymous: Account a = AccountHandler.insertNewAccount('My Test Account'); System.assertNotEquals(a,null); System.assertEquals('test','success');

An interesting line of apex code here is the System.assertEquals('test','success'); assertion. This is similar to the technique mentioned in Adding Eval() support to Apex where an resulting exception is used to return the result from anonymous apex. If I just start my Apex class with that assertion then in theory the test would pass...

If fact, it does! Replacing the method body with just that assertion and returning null causes the challenge to pass. My guess would be Trailhead code is looking for the "System.AssertException: Assertion Failed: Expected: test, Actual: success" in the response.

UPDATE: As mentioned above, Salesforce have subsequently removed this assertion. I learned through Salesforce that the final assertion was intended to rollback any side effects of the challenge check. This makes sense. It seems like it would be an ideal scenario for my idea to Run anonymous apex as if it were a test case.