OK, so after last time's brief introduction I'll share with you a Log4Net extension that I've made. It's nothing really too complicated but I hope it will highlight what I feel are the advantages of this technique.
So, on to business. If you're like me you'll like your logging code. I think logs are wonderful, if only to check that your code is doing what you think it is. Of course, there's always the chance that you'll have too much logging, but that's what log levels are for, right? ;)
The following is a common pattern I use for logging at pretty much every level (I've shown Debug here):
int someValue = 3;
if (log.IsDebugEnabled)
{
log.DebugFormat("This is a value: {0}", someValue);
}
Here I have a value I want to log, so I check that we should log and then log out the value. In this case I guess the check is superfluous, as the statement won't be output if we're not logging at debug anyway, but I like to get into the habit of checking so that when I need to log something like this:
if (log.IsDebugEnabled)
{
StringBuilder builder = new StringBuilder();
for (int i = 0; i < 100; i++)
{
builder.Append(GetSomeLogStatement(i));
}
log.Debug(builder.ToString());
}
I only go into the long running loop if I'm going to get some logging output from it.
When debugging code I like to have log statements that show where the execution path is going. The easiest way of doing that is to output a log statement when you enter a public method, but if you're doing this a lot then that's a lot of code being reproduced.
That's when I thought about making an extension method to handle all this for me. Here's the code:
public static void LogMethodParameters(this ILog logger, Level level,
string methodName, params object[] parameters)
{
try
{
if (logger == null)
{
throw new ArgumentNullException("logger");
}
if (level == null)
{
throw new ArgumentNullException("level");
}
if (methodName == null)
{
throw new ArgumentNullException("methodName");
}
if (logger.Logger.IsEnabledFor(level))
{
StringBuilder builder = new StringBuilder();
builder.AppendFormat("Method: [{0}]. ", methodName);
if (parameters != null && parameters.Length > 0)
{
// parameters.Length is at least 1
builder.AppendFormat("Parameters: (p0: [{0}]", GetParameterDisplayValue(parameters[0]));
for (int i = 1; i < parameters.Length; i++)
{
builder.AppendFormat(", p{0}: [{1}]", i, GetParameterDisplayValue(parameters[i]));
}
builder.Append(")");
}
logger.Logger.Log(null, level, builder.ToString(), null);
}
}
catch (Exception ex)
{
log4net.Util.LogLog.Error("Exception while logging exception", ex);
}
}
private static object GetParameterDisplayValue(object param)
{
return param != null ? param : "(null)";
}
public static void DebugMethodParameters(this ILog logger,
string methodName, params object[] parameters)
{
LogMethodParameters(logger, Level.Debug, methodName, parameters);
}
Like I say, it's nothing too complicated, but it allows you to include this line at the top of each of your public methods:
log.DebugMethodParameters("Method", 1, 2, 3);And you don't need to worry about anything else, your log file will show that you entered the method with those parameters.
What I wanted to do was use reflection to figure out what the current method was and what the parameter values are, but this was just a little side task I had to do while in the middle of something else.
Here are some additions I could make to this method:
- Use reflection to get the method name and parameter names
- Incorporate the Visual Studio 2008 ObjectDumper sample to drill down into complex objects to provide a fuller picture of non-primitive types
- Allow custom formatting of the log output
