CocoaConf 2011

No Comments

Today I attended the first day of CocoaConf, an iOS/OS X development conference near Columbus, OH. This is both the first time this conference has been held and the first Apple-related conference that I have attended. So far I have been very impressed with both the quality and variety of information being presented. There were a few rough edges (and a few spinning beach balls), but on the whole the event was very well organized. Thanks to everyone who had a hand in putting this together!

Sitting here taking stock of the day, I realized that there were two important takeaways from the day. So important that I decided to dust off my blog.

First, this was a good reminder to me of how important it is to surround yourself with people who know more than you do. I have been working in iOS for about a year and a half, first as a hobby and then professionally. I am at the point where I am starting to get a glimpse of how much I don’t know. This is actually encouraging to me… it has been my experience that if you pick up a new skill quickly and begin to feel like you are pretty good at it then you probably just haven’t figured out just how deep things go. Today I saw a small part of the iceberg under the water, and that is is a powerful motivator to keep learning and exploring. However, I only got this glimpse because I was here to listen to the presentations and conversations of those who are much more advanced than I am. If you think you are the smartest person in the room then go find a different room, and bring something to take notes with.

Secondly, this experience has reinforced my belief that learning new languages and platforms is an essential form of professional development. As a .NET web developer I have been writing essentially the same line of business app over and over for 10 years. Sure, there have been new tools and libraries, but businesses are slow to adopt new technologies, and tried-and-true patterns often win out over exercising the new hotness. This can get tedious, and worse, it can reinforce ideas through repetition rather than critical thinking.

Stepping away from the platform you are comfortable with offers a broader perspective, new ways to look at old problems, and a great deal of mental stimulation. However, I think you have to dig in deeper than “Hello World” and work on small project that addresses real world issues. This opens up many learning opportunities. What are the pain points? Why are those pain points the same/different from the platform you normally use? What patterns have emerged to address those issues, and what parts of the platform inspired people to build tools?

Beyond exercising a new platform in a non-trivial way, I think it is important to attend conferences and user groups. Sitting in a room full of people who have a fundamentally different view of the world can help you step back and revaluate many of the ideas that you may take for granted.

So, long story short, I am having a great time, learning a ton, and I hope that you make the time to try something new!

GiveCamp 2010

No Comments

I spent the weekend participating in the Southwest Ohio GiveCamp. I had heard about this event a couple of times at CINNUG meetings and decided to donate some time to try to help out. I am really glad I did.

Our team was assigned a project for the Dayton Battle of the Businesses. This is a phenomenal organization that raises an average of $60,000 a year for the Dayton Special Olympics. Their team registration process was paper-based so we built a pretty full-featured team management application. I am really proud of the way the project came out.

The project could not have been completed on time without the hard work and long hours donated by Ben Von Handorf, Brian Vacha, James Roberts, Mike Wood, and Steve Daum. We were also very fortunate to have Ron Sochocki and Diane Cox as our business contacts. They provided us great direction (and cookies!) and were a real pleasure to work with.

If you are a web developer or graphic artist in the Cincinnati area, I strongly encourage you to participate in this event next year. This year developers donated roughly $144,000 worth of time… 23% of the charities’ annual budget. One long weekend can make a big impact.

log4net Tutorial

No Comments

log4net is a versatile, widely-used logging package. The following article is provided as a quick tutorial for developers who would like to learn how to integrate and use log4net in their projects.

Over the course of this tutorial you will create a sample application that demonstrates most of log4net’s features. The highly-contrived goal is to model the reporting structure and activities of an office. The completed project is available for download.

Project Setup

We’ll begin by creating a console application, integrating log4net, and making a test logging call. One of the benefits of using log4net is how easily it can be added to a project.

Project Setup

First we need to create the basic application structure:

  • Create a new Blank Solution named OrgChart
  • Add a Console Application project named “OrgChart.UI”
  • Add an Application Configuration File (App.config) to the project
  • Add a Class Library project named “OrgChart.Data”
  • Remove the file “Class1.cs” from the project
  • Add a reference to the Data project into the UI project

Assuming you have already downloaded and unpacked log4net, add a reference to log4net.dll into both projects.

Configuration

Next we need to configure log4net. Define the configuration section by adding the following block to App.config:

<configuration>
  <configSections>
    <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
  </configSections>
</configuration>

Now you can add the configuration section:

<configuration>
  ...
  <log4net>
    <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
      <layout type="log4net.Layout.SimpleLayout" />
    </appender>
    <root>
      <level value="ALL" />
      <appender-ref ref="ConsoleAppender" />
    </root>
  </log4net>
</configuration>

This configuration block instructs the root (default) Logger to accept all log messages. It also associates the root Logger with an Appender that will write logged messages to the console. Loggers are the objects you will interact with in code. They expose the ILog interface which provides the methods used to log messages. Loggers are also responsible for filtering messages based on their level. Appenders are responsible for handling the messages sent to the Loggers. There are Appenders available for a variety of output destinations such as flat files, databases, and email. Multiple Appenders may be defined for an application. A list of Appenders and configuration samples are available on the log4net project site.

As the last configuration step, add the following line to the end of the AssemblyInfo.cs file in the UI project:

[assembly: log4net.Config.XmlConfigurator(Watch=true)]

This attribute instructs log4net to load its configuration from the application’s configuration file. It is possible to configure log4net to read its configuration from a different file. Setting the Watch parameter to true causes log4net to actively monitor the configuration file for changes.

Creating and Using a Logger

A logger object can be acquired by calling LogManager.GetLogger(). For reasons that will be explained shortly, you will typically create a static instance of a logger in each of your classes. Logging methods are exposed through the ILog interface.

The following code shows the complete console application:

using System;
using log4net;

namespace OrgChart.UI
{
    class Program
    {
        private static ILog _log = LogManager.GetLogger(typeof(Program));

        static void Main(string[] args)
        {
            _log.Info("OrgChart start");

            // TODO: add code here

            _log.Info("OrgChart stop");
            Console.WriteLine("Press [Enter] to exit...");
            Console.ReadLine();
        }
    }
}

Run the application and you should see the following output:

INFO - OrgChart start
INFO - OrgChart stop
Press [Enter] to exit...

That’s a good start; everything we need to use log4net is in place and working. Let’s move forward and explore the features log4net offers in more detail.

Logging Methods and Message Levels

Now that the basic structure of the application is in place we can get down to the business at hand: creating an org-chart and modeling office behavior. Begin by creating a class named “Employee” in the data project:

using System;
using log4net;

namespace OrgChart.Data
{
    public class Employee
    {
        private static ILog _log = LogManager.GetLogger(typeof(Employee));

        public string FirstName { get; private set; }
        public string LastName { get; private set; }

        public Employee(string firstName, string lastName)
        {
            FirstName = firstName;
            LastName = lastName;
            _log.Debug( String.Format("Employee {0} {1} created", FirstName, LastName ));
        }
    }
}

Note the logging call in the constructor. While developing the application it may be useful to confirm that a new Employee was created, but once the application is complete we would only want to log down to this detail when debugging a problem. This is a perfect time to use the Debug() method of the logger.

The ILog interface provides the following methods:

  • Debug(Object message)
  • Info(Object message)
  • Warn(Object message)
  • Error(Object message)
  • Fatal(Object message)

The level of the message is determined by the method used. Also note that the message parameter is of type Object, not String. Non-string messages are automatically converted to strings via their ToString() method unless a custom log4net Object Renderer has been created and registered for the message type. All of these methods have a second signature that takes a message and an exception. When an exception is passed its message and stack trace will be logged along with the message object.

We can’t have our employees running amok so we will need some managers. Create a class named “Manager” in the data project. This class derives from Employee and contains a list of Employees.

using System;
using System.Collections.Generic;
using log4net;

namespace OrgChart.Data
{
    public class Manager : Employee
    {
        private static ILog _log = LogManager.GetLogger(typeof(Manager));

        private List<Employee> _employees = new List<Employee>();

        public Manager(string firstName, string lastName)
            : base(firstName, lastName) { }

        public void AddEmployee(Employee employee)
        {
            _employees.Add(employee);
        }
    }
}

Our hypothetical office has the following structure:

  • Alice Anderson
    • Bob Baker
      • Carol M Conner
    • David Dunn
      • Carol A Conner

It’s unfortunate that the data model does not support middle initial since we have two employees named Carol Conner. Too late to change it now so let’s move forward. Add the following code to the Program class to create the office staff:

using OrgChart.Data;
...
_log.Info("OrgChart start");

Manager alice = new Manager("Alice", "Anderson");
Manager bob = new Manager("Bob", "Baker");
Employee carolM = new Employee("Carol", "Conner");
Manager david = new Manager("David", "Dunn");
Employee carolA = new Employee("Carol", "Conner");

alice.AddEmployee(bob);
alice.AddEmployee(david);
bob.AddEmployee(carolM);
david.AddEmployee(carolA);

_log.Info("OrgChart stop");

Run the application and you should see the following output:

INFO - OrgChart start
DEBUG - Employee Alice Anderson created
DEBUG - Employee Bob Baker created
DEBUG - Employee Carol Conner created
DEBUG - Employee David Dunn created
DEBUG - Employee Carol Conner created
INFO - OrgChart stop
Press [Enter] to exit...

Now that we have confirmed that the Employee objects are being created we really don’t want the debug messages showing up in the log. We also do not want to incur the overhead of the unneeded logging calls, especially if using an off-box store. We could comment out the logging statements or wrap them with #if DEBUG but then we would have to rebuild and redeploy if we want to debug a problem in production.

This situation is addressed in log4net by the loggers. Each logger may define a minimum level that a message must meet or exceed in order to be logged. You can configure this level by adjusting the element in the logger’s configuration block. The possible values from least restrictive to most are:

  • ALL
  • DEBUG
  • INFO
  • WARN
  • ERROR
  • FATAL
  • OFF

As you can see, these correspond directly to the logging methods exposed by ILog. ILog methods that fall below the minimum level are ignored by the logger. This evaluation does add overhead but it is negligible.

Change the value attribute of the root logger’s element to “INFO”…

<root>
  <level value="INFO" />
  <appender-ref ref="ConsoleAppender" />
</root>

…and then run the application:

INFO - OrgChart start
INFO - OrgChart stop
Press [Enter] to exit...

Just what we wanted; the DEBUG level messages no longer appear in the log. But what if you want different components to use different levels? Let’s look at that next.

Logger Configuration and Hierarchical Logging

Time to put people to work. Add the following method to the Employee class…

virtual public void DoWork()
{
	_log.Info(String.Format("{0} {1} is doing some work", FirstName, LastName));
}

…and the following method to the Manager class:

public override void DoWork()
{
	_log.Info(String.Format("{0} {1} is delegating", FirstName, LastName));

	foreach (Employee employee in _employees)
	{
		employee.DoWork();
	}
}

Now add the following line to the console application:

david.AddEmployee(carolA);

alice.DoWork();

_log.Info("OrgChart stop");

Running the application will show everyone busy:

INFO - OrgChart start
INFO - Alice Anderson is delegating
INFO - Bob Baker is delegating
INFO - Carol Conner is doing some work
INFO - David Dunn is delegating
INFO - Carol Conner is doing some work
INFO - OrgChart stop
Press [Enter] to exit...

Let’s make one refinement. The INFO messages being logged by the UI are not really that interesting and have nothing to do with tracking employee activity. We should change the configuration so that only ERROR messages from the UI are logged. INFO messages from the data model should continue to be logged.

Now is a good time to discuss one of the core features of log4net: hierarchical logging. When a Logger is created it is inserted into a virtual tree of Loggers based on its name. For example, when a logger named “OrgChart.Data.Employee” is created it is automatically considered to be a descendent of the loggers “OrgChart” and “OrgChart.Data”, even if those Loggers have not been created. At the root of the virtual tree is the root logger. It is created automatically and cannot be accessed directly.

As you probably guessed, the element in the log4net configuration controls the Root Logger. This brings up an important point; recall that when we created the Logger in the console application we passed the type of the class:

private static ILog _log = LogManager.GetLogger(typeof(Program));

This resulted in a Logger named “OrgChart.UI.Program”. However, when we adjusted the level of the root logger it was still affected. This is because Logger configuration is inherited. Unless overridden at some level in the virtual tree, every Logger inherits the settings of the root logger.

To specify the settings for a particular logger you can add a element to the log4net configuration:

<root>
  <level value="INFO" />
  <appender-ref ref="ConsoleAppender" />
</root>
<logger name="OrgChart.UI">
  <level value="ERROR" />
</logger>
...

Note that the new element does not contain an element. In this case the OrgChart.UI Logger will evaluate a message’s level but not forward it to an Appender. Instead it will pass the message up the Logger hierarchy until it reaches a Logger with an Appender reference. The level of the message is not reevaluated by the higher-level Loggers.

A quick run shows that the INFO level messages from the UI are no longer being logged:

INFO - Alice Anderson is delegating
INFO - Bob Baker is delegating
INFO - Carol Conner is doing some work
INFO - David Dunn is delegating
INFO - Carol Conner is doing some work
Press [Enter] to exit...

Note that we accomplished this by configuring the logger named “OrgChart.UI”, not the logger we are actually creating in code which is named “OrgChart.UI.Program”. You may configure any Logger in the virtual tree regardless of whether it is actually in use; subordinate Loggers will automatically apply the configuration if they are created. By configuring the “OrgChart.UI” logger we are insulating the application against future changes. If a new UI class named “OrgChart.UI.Report” is created it will automatically adopt the correct logging policy.

Contexts and Layouts

Now that we have a detailed log of employee activity, Alice Anderson has approached us and asked us to confirm that Carol M is showing up for work. The five log messages that are showing up are clearly too much data to visually scan through so we need to find a way to filter out messages for employees other than Carol M.

log4net includes several filter classes, but before we jump into that we have a bigger problem: what exactly are we going to filter on? The log messages for Carol M and Carol A are identical. In order to differentiate the messages we will need some additional context.

In a multi-user, multi-application environment it can be difficult to isolate the logging data you are looking for. You may want to trace a single user’s activity or isolate exceptions based on a server name. To facilitate this log4net allows you to tag log messages with developer-defined identifiers called Context Properties.

The factory class used to create a Context Property determines its scope. For example, Context Properties created using the ThreadContext class are in-scope for all logging calls that occur on the same thread. A detailed discussion of Contexts and scope can be found on the log4net project site.

Let’s start with a simple example. Assume that our application is being used to model offices for several different companies. In order to distinguish our five employees we will create a Context Property named “Company”. Add the following line to the Main() method:

static void Main(string[] args)
{
	ThreadContext.Properties["Company"] = "ACME";

	_log.Info("OrgChart start");

Every logging call on this thread will now be tagged with the “Company” property. However, if you run the application you will not see this information appear in the log. This is because the SimpleLayout associated with the Appender does not print Context Properties. We’ll need to address this before we move on.

As mentioned above, Appenders are responsible for sending a log message to a particular destination, but the format of that message is determined by a Layout. The SimpleLayout class is useful for quick testing but is not appropriate for normal use. Let’s make a quick change to the log4net configuration:

<appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
	<!--<layout type="log4net.Layout.SimpleLayout" />-->
	<layout type="log4net.Layout.PatternLayout">
		<conversionPattern value="%-5level [%property{Company}] - %message%newline" />
	</layout>
</appender>

The PatternLayout class allows you to define the format of messages using a set of tokens. In this example we are going to output the message level (padded to 5 characters), the “Company” Context Property, and the message. A complete list of tokens appears in the PatternLayout documentation.

Note: When you are trying to track down a problem it can be helpful to include the sequence %logger.%method in the pattern. If you follow the pattern of using a class’ type to initialize its logger then %logger will resolve to the class’ fully qualified class name. If you append .%method to the end then you get the fully qualified name of the method where the message was logged.

If we run the application now you will see the “Company” Context Property value:

INFO  [ACME] - Alice Anderson is delegating
INFO  [ACME] - Bob Baker is delegating
INFO  [ACME] - Carol Conner is doing some work
INFO  [ACME] - David Dunn is delegating
INFO  [ACME] - Carol Conner is doing some work
Press [Enter] to exit...

How can we use Context Properties to help distinguish between Carol M and Carol A? One approach would be to differentiate them by manager. Within each manager’s DoWork() method we could set a Context Property named “Manager” but this is problematic. What if there are multiple levels of managers? In that case each Manager would need to set the Context Property back to its previous value when the method exits. What happens if an exception is thrown and the context is not cleaned up? How would you adapt this approach if you needed to filter by someone’s grand-manager?

log4net provides a solution to this problem in the form of Context Stacks. A Context Stack is just like a Context Property except it is a stack; multiple values can be pushed into it and then popped out when appropriate. An example will make this clearer. Update the Manager.DoWork() method so that it looks like this:

public override void DoWork()
{
	_log.Info(String.Format("{0} {1} is delegating", FirstName, LastName));

	using (ThreadContext.Stacks["Manager"].Push(String.Format("({0} {1})", FirstName, LastName)))
	{
		foreach (Employee employee in _employees)
		{
			employee.DoWork();
		}
	} // value will be popped off the stack here
}

Before work is delegated the manager’s name is pushed into the “Manager” Context Stack. Notice how log4net makes use of the IDisposable pattern to make sure that the value is popped back out when the block is exited. Context Stacks are added to the Layout using the same syntax as Context Properties:

<layout type="log4net.Layout.PatternLayout">
	<conversionPattern value="%-5level [%property{Company}] [%property{Manager}] - %message%newline" />
</layout>

Run the application now…

INFO  [ACME] [(null)] - Alice Anderson is delegating
INFO  [ACME] [(Alice Anderson)] - Bob Baker is delegating
INFO  [ACME] [(Alice Anderson) (Bob Baker)] - Carol Conner is doing some work
INFO  [ACME] [(Alice Anderson)] - David Dunn is delegating
INFO  [ACME] [(Alice Anderson) (David Dunn)] - Carol Conner is doing some work
Press [Enter] to exit...

…and you will see that the messages contain the full reporting hierarchy of the Employee. This gives us a clear way to distinguish between Carol M and Carol A so let’s start filtering.

Filtering

A Filter is an object that controls which messages are processed by an Appender. Filters do not affect Loggers; filtering out DEBUG messages does not disable the ILog.Debug() method in the same way that the logger configuration does. A Filter only affects the Appender for which it is defined.

The Filter classes provided by log4net perform matching based on a given message characteristic. For example, one of the classes we will be using is the PropertyFilter class which matches a specified pattern against the value of a Context Property . A complete list of Filter classes can be found on the log4net project site.

If multiple Filters are defined for an Appender they form a pipeline in which each Filter votes on the message as it passes through. Filters may return an Accept, Deny, or Neutral vote. Accept causes the message to be immediately logged, Deny causes the message to be immediately discarded, and Neutral allows the message to be passed on to the next Filter in the pipeline. If a message reaches the end of the pipeline with no Deny votes then it is logged. By default most filters will return Accept on a match or Neutral on a non-match. To configure a Filter to return Deny on a match you can add to the filter definition.

The filter we want to define is something like “all messages that contain “Carol Conner” and have a Manager property that contains “Bob Baker”. Unfortunately, you can not combine filters to create and/or logic. This is where an understanding of how the Filter pipeline works comes in handy. Add the following filters to the ConsoleAppender:

<appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
  ...
  <filter type="log4net.Filter.PropertyFilter">
	<Key value="Manager" />
	<RegexToMatch value="^((?!Bob Baker).)*$" />
	<AcceptOnMatch value="false" />
  </filter>
  <filter type="log4net.Filter.StringMatchFilter">
	<StringToMatch value="Carol Conner" />
  </filter>
  <filter type="log4net.Filter.DenyAllFilter" />
</appender>

The first filter evaluates a message’s “Manager” Context Property. It is making use of the element which may be used instead of the element. The regular express translates to “does not contain Bob Baker”. Note that we have also included the element and set its value attribute to false. The net effect is that this filter will deny (and therefore immediately discard) any message that does not have a “Manager” Context Property that contain “Bob Baker”. All other messages will receive a neutral vote and be passed on to the next filter.

The first filter is enough to remove Carol A, but it is not specifically isolating Carol M. Any employee of Bob Baker would pass this filter. To tighten this down the second filter will accept (and therefore immediately log) any message that contains “Carol Conner”. All other messages (such as those for Bob’s other employees) will receive a neutral vote and be passed on to the next filter. Finally, the third filter will deny all messages. This prevents a message from being logged unless a previous Filter has specifically Accepted it.

We’ve finally accomplished our task. Run the application and you will see the log message that confirms Carol M is hard at work:

INFO  [ACME] [(Alice Anderson) (Bob Baker)] - Carol Conner is doing some work
Press [Enter] to exit...

Performance

One concern about heavily instrumenting code is the impact it will have on performance. There is a detailed discussion of this topic on the log4net project site. Assuming that you are willing to incur the overhead of conditional logging, there is one situation you should still watch out for. Add the following method to the Employee class…

public string GetLunchDestination()
{
	System.Threading.Thread.Sleep(5000);
	return "I don't know, where do you want to go?";
}

…and then add this line to the Program class:

alice.DoWork();

_log.Debug("Lunch Destination: " + bob.GetLunchDestination());

_log.Info("OrgChart stop");

Run the application and watch for the pause before “Press [Enter] to exit…” appears. Even though DEBUG messages are disabled, the parameters to the call were still evaluated. This resulted in an unnecessary (and expensive) operation being performed. The solution recommended by the log4net documentation is to check the status of the logger before making the logging call. For example:

if (_log.IsDebugEnabled)
{
	_log.Debug("Lunch Destination: " + bob.GetLunchDestination());
}

This does introduce a second evaluation, but that is much faster than processing the parameters in this case. You may also want to use this approach when you are logging an object that has a non-trivial ToString() method. If you are just logging simple values there is no benefit to checking the logger status first.

Wrapping Up…

So there you go, you’re an expert! log4net is well documented so any topic you would like more information on is most likely covered somewhere on the log4net project site.

I have a few additional tips on using log4net but I will save those for a future post.

Exception Logging with ELMAH

No Comments

I became aware of ELMAH for the first time several months ago. Late to the party again. I played around with it a bit and was really impressed. When I mentioned it to a few of my friends they expressed an interest in learning more about it. I decided to dig in and put together an introductory article for ELMAH. There are a few articles already available, but this was mainly for my own education. I am sharing the results in a hope that it may help others come up to speed quickly on this very handy tool.

So first, what is ELMAH?

“ELMAH (Error Logging Modules and Handlers) is an application-wide error logging facility that is completely pluggable. It can be dynamically added to a running ASP.NET web application, or even all ASP.NET web applications on a machine, without any need for re-compilation or re-deployment.”

ELMAH is an exception logging facility, not a generalized logging library like log4net. There are no trace methods such as log.Debug() and log.Info(). Rather than being called from code, ELMAH detects unhandled exceptions and logs them automatically along with server variables and form data. Logged exceptions may be viewed remotely using a securable, read-only interface. ELMAH can also be configured to send notifications via email and Twitter.

I’ll begin by giving a brief overview of the ELMAH interface and then move on to integrating ELMAH into an application.

Remotely Viewing Exception Data

When you load the ELMAH interface you will see a summary of all logged exceptions:

ELMAH Summary Page

Note the options along the top. ELMAH provides pull notifications via RSS and the ability to download the log for analysis.

Clicking on the “Details…” link for an entry will display the exception type, message and stack trace:

ELMAH Detail Page 1

Nothing too amazing about that, but keep scrolling down…

ELMAH Detail Page 2

…and you will find that it also displays the server variables. Also, notice the subtle link to the “Original ASP.NET error page”? Clicking that link will display the following:

ELMAH Yellow Screen of Death

It’s your old friend, the yellow screen of death! ELMAH logs all the information necessary to reproduce it. Note that this is in no way controlled by the element.

NOTE: If you are using ASP.NET MVC there are times when this link will not appear. ELMAH only stores the extended information it needs to reproduce the YSOD when the unhandled exception is derived from HttpException.

When an exception is left unhandled in an ASP.NET Web Forms application the system will throw an HttpUnhandledException (which derives from HttpException). When an exception is generated in an ASP.NET MVC view the system throws an HttpException. In both of these cases the “Original ASP.NET error page” link will be displayed.

On the other hand, exceptions thrown from an ASP.NET MVC controller will bubble all the way up. If a NullReferenceException is thrown, the YSOD will not be available in ELMAH since the unhandled exception does not derive from HttpException.

Navigate back and click the “XML” link. This looks like the same information you have already seen, but scroll down to the bottom and you will also find the complete form collection:

ELMAH XML Detail

Something that may not have jumped out at you is the “Host” column on the summary page. When your application is being hosted by multiple servers (such as in a load balancing scenario), ELMAH can consolidate all of the errors to a single log. This can be really handy when you are trying to track down a problem that is node specific.

Integrating ELMAH

Adding ELMAH to your application generally does not require any code changes or rebuilds and can be completed in just a few minutes. Before we jump into that, a quick word on compatibility. Under ASP.NET 1.x, the ELMAH core requires full trust and does not support all of the log stores. Under ASP.NET 2.0 and 3.5, the ELMAH core will work with medium trust, but some of the log stores still require full trust. See the ErrorLogImplementations page on the ELMAH project site for more information.

The first step is to copy the appropriate ELMAH assembly (Elmah.dll) into your application’s bin directory. You can download the latest version from the ELMAH project site. The ELMAH download contains assemblies compiled for .NET 3.x, 2.0, and 1.x. Your application does not need to reference this assembly.

The next step is to update the application’s web.config. First, the ELMAH configuration sections must be defined:

<configSections>
	...
	<sectionGroup name="elmah">
		<section name="security" requirePermission="false" type="Elmah.SecuritySectionHandler, Elmah"/>
		<section name="errorLog" requirePermission="false" type="Elmah.ErrorLogSectionHandler, Elmah" />
	</sectionGroup>
	...
</configSections>

NOTE: If you are integrating ELMAH with an ASP.NET 1.x application do not include the requirePermission attribute. This is also true for the other

elements discussed later.

An HTTP module must be added…

<httpModules>
	...
	<add name="ErrorLog" type="Elmah.ErrorLogModule, Elmah"/>
	...
</httpModules>

…as well as an HTTP handler:

<httpHandlers>
	...
	<add verb="POST,GET,HEAD" path="elmah.axd" type="Elmah.ErrorLogPageFactory, Elmah" />
	...
</httpHandlers>

Finally, the ELMAH configuration section must be added:

<configuration>
	...
	<elmah>
		<security allowRemoteAccess="0" />
	</elmah>
	...
</configuration>

NOTE: The allowRemoteAccess attribute controls whether ELMAH is accessible from a remote host. It would be unwise to set this to “1″ until you have a strategy in place for securing ELMAH. This will be covered below.

That’s all there is to it. Enter the address http://(host)/(application)/elmah.axd in your browser and you should see the ELMAH interface.

How is ELMAH logging errors if it is not being called from your code? As you may have guessed from the web.config entries, ELMAH is implemented using HTTP modules and handlers. The ErrorLogModule module subscribes to the HttpApplication.Error event. When the event is fired due to an unhandled exception, the module retrieves the exception from Server.GetLastError() and writes it to the configured error log(s). The default error log is MemoryErrorLog which simply keeps the log data in memory for the lifetime of the application. The ELMAH UI is provided by the ErrorLogPageFactory HTTP handler which services requests for elmah.axd.

ELMAH does not “handle” exceptions or affect the behavior of the application in any way; it simply observes an exception, logs it, and sends notifications if configured to do so.

Beyond “Hello, ELMAH”

The simple configuration presented in the previous section is enough to get ELMAH up and running so that you can experiment with it. However, for serious use a few additional topics need to be addressed.

Persistent Error Logs

MemoryErrorLog is generally not appropriate for a production environment due to its lack of persistent storage. ELMAH provides database and file backed alternatives such as SqlErrorLog and XmlFileErrorLog.

To use one of these persistent error logs an entry must be added to the configuration section:

<configuration>
	...
	<elmah>
		<security allowRemoteAccess="1" />
        <errorLog type="Elmah.SqlErrorLog, Elmah" connectionStringName="connectionString" />
	</elmah>
	...
</configuration>

In this example the SqlErrorLog will use a pre-existing connection string to connect to the application’s database. Errors will be logged to the ELMAH_Error table which can be created using a script from the ELMAH download.

In an environment where you have multiple applications there are a couple of different logging strategies. You might decide that each application should log exceptions to its own database. In this case the configuration above is sufficient. However, you may decide to log all exceptions from all applications to a centralized ELMAH database. In this case ELMAH must be able to associate exceptions with the application that generated them. This requires you to add the applicationName attribute to the errorLog element:

<configuration>
	...
	<elmah>
		<security allowRemoteAccess="1" />
        <errorLog type="Elmah.SqlErrorLog, Elmah" connectionStringName="connectionString" applicationName="myApp"  />
	</elmah>
	...
</configuration>

Notifications via Email and Twitter

ELMAH can send notifications via email and Twitter. To enable notifications, first define the errorMail and errorTweet configuration sections:

<sectionGroup name="elmah">
	...
	<section name="errorMail" requirePermission="false" type="Elmah.ErrorMailSectionHandler, Elmah" />
	<section name="errorTweet" requirePermission="false" type="Elmah.ErrorTweetSectionHandler, Elmah"/>
	...
</sectionGroup>

Next the email and Twitter HTTP modules must be registered:

<httpModules>
	...
	<add name="ErrorMail" type="Elmah.ErrorMailModule, Elmah" />
	<add name="ErrorTweet" type="Elmah.ErrorTweetModule, Elmah"/>
	...
</httpModules>

Finally the errorMail and errorTweet configuration sections must be added:

<elmah>
	...
	<errorMail
	    from="elmah@example.com"
	    to="admin@example.com"
	    subject="..."
	    priority="Low|Normal|High"
	    async="true|false"
	    smtpPort="25"
	    smtpServer="smtp.example.com"
	    useSsl="true|false"
	    userName="johndoe"
	    password="secret"
	    noYsod="true|false" />
	...
	<errorTweet
	    userName="johndoe"
	    password="secret" />
	...
</elmah>

You will now get spammed be notified every time an unhandled exception occurs. Rather than explore how this might act as a powerful motivator to adopt Test-Driven Development, I’ll move on to describing filters.

Filtering

ELMAH provides a flexible filtering mechanism that allows you to decide which exceptions are logged, as well as which exceptions result in notifications. To enable filtering, first define the errorFilter configuration section:

<sectionGroup name="elmah">
	...
	<section name="errorFilter" requirePermission="false" type="Elmah.ErrorFilterSectionHandler, Elmah"/>
	...
</sectionGroup>

Next the filter HTTP modules must be registered:

<httpModules>
	...
	<add name="ErrorFilter" type="Elmah.ErrorFilterModule, Elmah"/>
	...
</httpModules>

Filters are declared using a set of evaluation elements. Evaluation elements may be combined using and elements. Here is a simple filter that prevents all 404 exceptions from being logged:

<elmah>
	...
	<errorFilter>
		<test>
				<equal binding="HttpStatusCode" value="404" type="Int32" />
		</test>
	</errorFilter>
	...
</elmah>

That’s probably too broad of a filter. You may want 404 errors logged to the database, but you probably don’t want to receive an email every time one occurs. An additional evaluation can be included with an element:

<elmah>
	...
	<errorFilter>
		<test>
			<and>
				<equal binding="HttpStatusCode" value="404" type="Int32" />
				<regex binding="FilterSourceType.Name" pattern="ErrorMailModule" />
			</and>
		</test>
	</errorFilter>
	...
</elmah>

Now 404 errors will not be “logged” to the mail module. As a further example, suppose that for some strange reason you don’t want to receive an email when an ApplicationException occurs. ELMAH only supports a single and element, so additional tests must be included with an element:

<elmah>
	...
	<errorFilter>
		<test>
			<or>
				<and>
					<equal binding="HttpStatusCode" value="404" type="Int32" />
					<regex binding="FilterSourceType.Name" pattern="ErrorMailModule" />
				</and>
				<and>
					<is-type binding="BaseException" type="System.ApplicationException" />
					<regex binding="FilterSourceType.Name" pattern="ErrorMailModule" />
				</and>
			</or>
		</test>
	</errorFilter>
	...
</elmah>

If you had a large set of filters it might become cumbersome to declare them this way. Fortunately, more complex filtering can be defined by embedding JavaScript in the element. You may read the filtering article on the ELMAH project site for more information.

Securing ELMAH

The information that ELMAH makes available could be used to compromise your application so it’s very important that you secure it. To do this you must restrict access to elmah.axd. This can be accomplished by adding the following entries to web.config:

<configuration>
	...
	<location path="elmah.axd">
		<system.web>
			<authorization>
				<allow roles="DomainName\GroupName" />
				<deny users="*" />
			</authorization>
		</system.web>
	</location>
	...
</configuration>

NOTE: This example assumes that you are using Windows security but Forms security may be used instead.

Now that the ELMAH interface has been secured, you can enable remote access by setting the allowRemoteAccess attribute to “1″:

<configuration>
	...
	<elmah>
		<security allowRemoteAccess="1" />
	</elmah>
	...
</configuration>

I have seen a suggestion that you secure ELMAH by defining a path for elmah.axd and then securing that path. For example, you could register the ELMAH HTTP handler like this:

<httpHandlers>
	<add verb="POST,GET,HEAD" path="/admin/elmah.axd" type="Elmah.ErrorLogPageFactory, Elmah" />
</httpHandlers>

This certainly works but I prefer to leave elmah.axd in the root of the application. Most of the applications I am working on are ASP.NET MVC so I like to avoid adding paths that are not related to a controller. This also prevents adjusting the application’s routes since *.axd is automatically ignored. If you are using ASP.NET MVC and would like to secure elmah.axd with a path you will need to make an entry like this in Global.asax.cs:

public static void RegisterRoutes(RouteCollection routes)
{
	routes.IgnoreRoute("{resource}.axd/{*pathInfo}");
	routes.IgnoreRoute("admin/elmah.axd/{*pathInfo}");
	...
}

Dealing with the Expected

ELMAH only sees unhandled exceptions, so any exceptions that are caught and not rethrown will not be logged. There are scenarios beyond simple try/catch blocks where this can happen:

  • Server.ClearError() is being called from the Application_Error method
  • An ASP.NET MVC controller has been decorated with the [HandleError] attribute (more on this below)
  • The Enterprise Library Exception Handling Application Block is being used, and the PostHandlingAction property of an exception policy is set to “None” instead of “NotifyRethrow” or “ThrowNewException”

The next two sections provide some suggestions on how to deal with this issue.

Logging Handled Exceptions

There are times when you may not want to let an exception go unhandled, or you have no control over whether it is handled or not. For example, exceptions thrown by ASP.NET web services are automatically handled. If you run into this issue you can use the ErrorSignal class to signal ELMAH that the exception should be logged. The following code will log an exception to ELMAH without rethrowing it:

using Elmah;
...
try
{
   ...
}
catch (Exception ex)
{
    ErrorSignal.FromCurrentContext().Raise(ex);
}

ASP.NET MVC [HandleError]

The [HandleError] attribute acts as a try/catch block around all of your controller methods. When an exception is caught the user is automatically shown the “Error” view. The exception is not rethrown. I have seen two suggestions on how to deal with this issue.

Scott Hanselman suggested removing the [HandleError] attribute and using the element to perform the automatic redirect to the “Error” view instead. This gives the user a friendly error page and still leaves the exception unhandled so ELMAH can log it.

Atif Aziz (the author of ELMAH) suggested subclassing HandleErrorAttribute so that it signals ELMAH when an exception is caught.

It’s up to the reader to decide which approach fits best in their application. I prefer Scott Hanselman’s approach since it doesn’t require a maintenance developer to know anything about ELMAH.

Summary

ELMAH brings a lot of value for minimal effort. The depth of information that it logs and the tools it provides makes it an attractive addition to a project even if another logging solution is already in place.

My only complaint is that the ELMAH documentation seems a bit fragmented. I had to consult several different resources to collect the information that appears in this article. That being said, the ELMAH download contains a very well documented web.config file that should answer most configuration related questions.

For more information:

Creating a Color Scheme

No Comments

Disclaimer: I do not have a background in color theory or graphic design. This article is based purely on experimentation that resulted in positive results.

This past year I was working on an ASP.NET application for one of my clients who had very clear ideas about what the user interface should look like. One of the pages required a grid that contained blue, red, and green columns. For readability the grid also needed to be striped.

Some people have a natural feel for working with colors. I am not one of them, so coming up with a set of colors that worked well together was a challenge. I tried using some color scheming utilities but was not satisfied with the results. After some experimentation and research (that I will not bore you with), I found a method that produces passable results and is so easy a cavem… well, it’s easy.

First, I am going to select a base color. This is the color with which all other colors must be harmonious. In my case the application is running under SharePoint which contains many shades of blue. There is a dark blue border that runs throughout the application so I am going to start with it. My color picker tells me that this color is:

#297acc

The base color is dark, so I am going to use it for the blue column header. Now I need two lighter shades of blue for the alternating rows. To do this, I am going to adjust the base color’s HSV values. Open the color dialog in your favorite drawing program. I usually use GIMP, but Paint.NET will work as well. Enter the base color and observe the HSV sliders:

As you can see, the S value can be adjusted to produce lighter shades of the selected color. I’m going to use an S value of 15 to create a medium shade for the even rows and an S value of 5 to create a light shade for the odd rows. This would produce a table column that looks like this:

#297acc (210, 80, 80)
#c2c7cc (210, 5, 80)
#adbdcc (210, 15, 80)
#c2c7cc (210, 5, 80)
#adbdcc (210, 15, 80)

That’s pretty ugly. The colors are too washed out. Looking back at the HSV sliders you can see that the brightness is controlled by the V value. I am going to crank that up to 100 for the medium and light colors:

#297acc (210, 80, 80)
#f2f8ff (210, 5, 100)
#d9ecff (210, 15, 100)
#f2f8ff (210, 5, 100)
#d9ecff (210, 15, 100)

Much better. Now I need to select colors for the red and green column. Clearly the H value is what needs to be adjusted, but to what values? There are many shades of red and green but most will not look right next to the base color.

Observe that the H value ranges from 0 to 360… just like the degrees in a circle. The key to selecting a set of harmonious colors is to pick colors that are equal degrees apart. For example, if you want six colors to chose from, select H values that are in increments of 60 (360/6 = 60). Let’s apply this to basic red:

#ff0000 (0, 100, 100) #ffff00 (60, 100, 100) #00ff00 (120, 100, 100)
#00ffff (180, 100, 100) #0000ff (240, 100, 100) #ff00ff (300, 100, 100)

Not surprisingly this produced all primary colors. Here is the same technique applied to a randomly selected color:

#338cd0 (206, 75, 82) #7733d0 (266, 75, 82) #d0338c (326, 75, 82)
#d07733 (26*, 75, 82) #8cd033 (86, 75, 82) #33d077 (146, 75, 82)

*notice the wrap… 326 + 60 – 360 = 26

Need a wider range of colors to select from? Just use a smaller interval. For example, I am going to start with my base color and adjust the H value in increments of 30:

#297acc (210, 80, 80) #2929cc (240, 80, 80) #7b29cc (270, 80, 80)
#cc29cc (300, 80, 80) #cc297b (330, 80, 80) #cc2929 (0, 80, 80)
#cc7b29 (30, 80, 80) #cccc29 (60, 80, 80) #7bcc29 (90, 80, 80)
#29cc29 (120, 80, 80) #29cc7b (150, 80, 80) #29cccc (180, 80, 80)

Getting back to the original goal, I need colors for the red and green column headers. Given the options above I like these:

#cc2929 and #29cc29

I can generate the medium and light shades of these colors using the same approach used for the base color (S values of 15 and 5 and a V value of 100). This yields the following colors:

#297acc (210, 80, 80) #cc2929 (0, 80, 80) #29cc29 (120, 80, 80)
#f2f8ff (210, 5, 100) #fff2f2 (0, 5, 100) #f2fff2 (120, 5, 100)
#d9ecff (210, 15, 100) #ffd9d9 (0, 15, 100) #d9ffd9 (120, 15, 100)
#f2f8ff (210, 5, 100) #fff2f2 (0, 5, 100) #f2fff2 (120, 5, 100)
#d9ecff (210, 15, 100) #ffd9d9 (0, 15, 100) #d9ffd9 (120, 15, 100)

Not bad. However, I think that the green header is not dark enough. Just as the S and V values can be adjusted to lighten a color, they can be adjusted to darken a color. I am going to change the V value from 80 to 60. This yields the following:

#297acc (210, 80, 80) #cc2929 (0, 80, 80) #1f991f (120, 80, 60)
#f2f8ff (210, 5, 100) #fff2f2 (0, 5, 100) #f2fff2 (120, 5, 100)
#d9ecff (210, 15, 100) #ffd9d9 (0, 15, 100) #d9ffd9 (120, 15, 100)
#f2f8ff (210, 5, 100) #fff2f2 (0, 5, 100) #f2fff2 (120, 5, 100)
#d9ecff (210, 15, 100) #ffd9d9 (0, 15, 100) #d9ffd9 (120, 15, 100)

Looks good, ship it! With more real-world formatting and data the output looks like this:

Rate CoF Spread
5 year 3.50% 3.30% 0.20%
10 year 4.95% 4.80% 0.15%
15 year 5.05% 4.90% 0.15%
20 year 5.20% 5.05% 0.15%

To Summarize:

  • Select a base color. Generally this is going to be a color that already appears on the page due to a logo or pre-existing styles.
  • Generate a set of harmonious colors by incrementing through the circular range of H values. Increments of 60, 30, or 15 will probably give you what you need.
  • Generate lighter and darker shades of a color by adjusting the S value. If the color becomes too washed out or too intense you can compensate with the V value.
  • Be consistent. If you lighten one color by setting S to 20, then lighten all colors by setting S to 20.

Any and all feedback is welcome! If you have a better way of doing this please let me know and I will update this article.