26 June 2011

Exception Logging Antipatterns

Here are some logging antipatterns I have seen again and again in real life production code. If your application has one global exception handler, catching and logging should be done only in this central place. If you want to provide additional information throw a new exception and attach the original exception. I assume that the logging framework is capable of dumping an exception recursively, that means with all inner exceptions and their stacktraces.

Catch Log Throw
catch (Exception ex)
{
    _logger.WriteError(ex);
    throw;
}

No additionally info is added. The global exception handler will log this error anyway, therefore the logging is redundant and blows up your log. The correct solution is to not catch the exception at all.

Catch Log Throw Other

catch (Exception ex)
{
    _logger.WriteError(ex, "information");
    throw new InvalidOperationException("information"); // same information
}
Same as Catch Log Throw, but now you have two totally unrelated log entries. Solution: use the InnerException mechanism to create a new exception and don't log the old one:
throw new InvalidOperationException("information", ex);

Log Un-thrown Exceptions
catch (Exception ex)
{
    var myException = new MyException("information");
    _logger.WriteError(myException);
    throw myException;
}

In this case an un-thrown exception is logged. This could cause problems, because the exception is not fully initialized until it was thrown. For example the Stacktrace property would be null. Solution: don't log, just attach the original exception ex to MyException:
throw new MyException("information", ex);

Non Atomic Logging
catch (Exception ex)
{
    _logger.WriteError(ex.Message);
    _logger.WriteError("Some information");
    _logger.WriteError(ex);
    _logger.WriteError("More information");
}

Several log messages are created for one cause. In the log they appear unrelated and can be mixed with other log message. Solution: Combine the information into one atomic write to the logging system: _logger.WriteError(ex, "Some information and more information");

Expensive Log Messages
{
    [...] // some code
    _logger.WriteInformation(Helper.ReflectAllProperties(this));
}
This one is really dangerous for your performance. An expensive log message is generated all the time even if the logging system is configured to ignore it. If you have expensive message, put the generation into an if block side by side with the logging statement:
if (_logger.ShouldWrite(LogLevel.Information))
{
    // do expensive logging here
    _logger.WriteInformation(Helper.ReflectAllProperties(this));

}
 

13 June 2011

Disable ASP.NET Development Server

I always forget how to stop the ASP.NET Development server from starting when I attach to the IIS for debugging, so here is the way to do it:
  1. Select the web or WCF project. Press F4 to show the property window. If only an empty window appears, repeat the process.
  2. Set the first property to "False".
Always_start_when_debugging
If your solution contain projects that start the ASP.NET Development Server you will enjoy my macro that sets this property solution wide:
Sub TurnOffAspNetDebugging()

    REM The dynamic property CSharpProjects returns all projects
    REM recursively. "Solution.Projects" would return only the top
    REM level projects. Use VBProjects if you are using VB :-).          
    Dim projects = CType(DTE.GetObject("CSharpProjects"), Projects)

    For Each p As Project In projects
        For Each prop In p.Properties
            If prop.Name = "WebApplication.StartWebServerOnDebug" Then
                prop.Value = False                
            End If
        Next
    Next
End Sub

Update: This solution no longer works for VS2012. An addin with the same functionality is available on GitHub: https://github.com/algra/VSTools 

12 June 2011

Feature Toggle or Feature Branch

I'm working in company that releases every two weeks with the goal to do weekly releases and eventually daily releases. We introduced Feature Toggles for the development of features that overlap a release without destroying Continuous Integration.

Recently I noticed that people start using Feature Toggles for features that take only a few hours to implement. In this case the effort to setup, configure and test the Feature Toggle is easily more than 50 percent of implementation effort. It would be much more efficient to create a branch and merge it one or two days later back to the trunk. The cost for having no continuous integration is less than the cost for using a toggle in this case.

Why are people doing this? One answer could be that they are entrapped by the possibility to dynamically turn features on or off. Another is process thinking: because there was a process that enforced feature branches for feature development it is believed that you now must use Feature Toggles. Another company specific reason is that we had feature branches coupled with a heavyweight process (including the setup of a complete cloned environment with automatic builds, databases, dozens of service, ...) that was so painful that everybody shivers when hearing the word Feature Branch.

Make sure that you are using feature toggles and feature branches for the right things. A lightweight feature branch needs much less brainpower than implementing of a toggle for the modification of an legacy feature.

30 March 2011

Why a Feature Toggle should be ‘OFF’ if it is undefined

When I first implemented some infrastructure supporting Feature Toggles I thought it was a good idea to have three states: on, off and undefined. If some code access a feature that is not defined it should throw an exception. The reason for this was that I used a fairly dynamic approach where a feature was identified by its name. This allows simple adding and removing of feature toggles without the static typing overhead. The drawback is that typing errors cannot be found by the compiler or interpreter, e.g. the feature is defined as “Toggle” but you write “togle”. In this case I thought it would be good to throw an exception.

But if you are developing a component that is is used in several applications than you have to define the feature in every applications configuration. Even if the feature should be disabled everywhere except in your test application. And if the feature is finished you have to remove the feature from all application configuration again. Error prone and time consuming.

Therefore an undefined feature toggle should always be treated as ‘OFF’.

16 February 2011

Visual Studio 2010 Javascript Snippets for Jasmine

Because Resharper 5 does not support live templates for Javascript I’m forced to use the built in VS2010 snippets. The default Javascripts snippets are located here:

%ProgramFiles%\Microsoft Visual Studio 10.0\Web\Snippets\JScript\1033\JScript

The ‘1033’ locale ID may be different for your country. I’m using the following snippets for creating Jasmine specs:

describe

<CodeSnippet Format="1.1.0" xmlns="http://schemas.microsoft.com/VisualStudio/2005/CodeSnippet">
  <Header>
    <Title>describe</Title>
    <Author>Christian Rodemeyer</Author>
    <Shortcut>describe</Shortcut>
    <Description>Code snippet for a jasmine 'describe' function</Description>
    <SnippetTypes>
      <SnippetType>Expansion</SnippetType>
    </SnippetTypes>
  </Header>
  <Snippet>
    <Declarations>
      <Literal>
        <ID>suite</ID>
        <ToolTip>suite description</ToolTip>
        <Default>some suite</Default>
      </Literal>
    </Declarations>
    <Code Language="jscript"><![CDATA[describe("$suite$", function () {
        $end$        
    });]]></Code>
  </Snippet>
</CodeSnippet>

it

<CodeSnippet Format="1.1.0" xmlns="http://schemas.microsoft.com/VisualStudio/2005/CodeSnippet">
  <Header>
    <Title>it</Title>
    <Author>Christian Rodemeyer</Author>
    <Shortcut>it</Shortcut>
    <Description>Code snippet for a jasmine 'it' function</Description>
    <SnippetTypes>
      <SnippetType>Expansion</SnippetType>
    </SnippetTypes>
  </Header>
  <Snippet>
    <Declarations>
      <Literal>
        <ID>spec</ID>
        <ToolTip>spec description</ToolTip>
        <Default>expected result</Default>       
      </Literal>    
    </Declarations>
    <Code Language="jscript"><![CDATA[it("should be $spec$", function () {
        var result = $end$       
    });]]></Code>
  </Snippet>
</CodeSnippet>

func

<CodeSnippet Format="1.1.0" xmlns="http://schemas.microsoft.com/VisualStudio/2005/CodeSnippet">
  <Header>
    <Title>function</Title>
    <Author>Christian Rodemeyer</Author>
    <Shortcut>func</Shortcut>
    <Description>Code snippet for an anonymous function</Description>
    <SnippetTypes>
      <SnippetType>Expansion</SnippetType>
      <SnippetType>SurroundsWith</SnippetType>
    </SnippetTypes>
  </Header>
  <Snippet>
    <Code Language="jscript"><![CDATA[function () {
        $selected$$end$
    }]]></Code>
  </Snippet>
</CodeSnippet>

10 February 2011

Removing the mime-type of files in Subversion with SvnQuery

If you add files to subversion they are associated with a mimetype. SvnQuery will only index text files, that means files without an svn:mime-type property or where the property is set to something like “text/*”. At work I wondered why I couldn’t find some words that I know must exist. It turned out that subversion marks files stored as UTF-8 files with BOM as binary, using svn:mime-type application/octet-stream. This forces the indexer to ignore the content of the file.

I used SvnQuery to find all files that are marked as binary, e.g. t:app* .js finds all javascript files and t:app* .cs finds all C# files. With the download button at the bottom of the results page I downloaded a text files with the results. Because svn propdel svn:mime-type [PATH] can work only on one file (it has no --targets option) I had to modify the text file to create a small batch script like this:

svn propdel svn:mime-type c:\workspaces\javascript\file1.js
svn propdel svn:mime-type c:\workspaces\javascript\file1.js
svn propdel svn:mime-type c:\workspaces\javascript\file1.js

After this change indexing worked again. I now run a daily query that ensures that no sources files are marked as binary.