01.18.05
That Yummy FreeSoftwareFeel: log4net Edition
So a little bit back Ryan wrote an article about
setting up log4net, as well as doing the grunt work of getting
it into our development environment. As we are getting used to it though,
I found that basic configuration to not be good enough. Here are the
improvements.
The current project I’m working on in ASP.Net is very user centered; I want
every log message to also record which user is making that request. This
is what the Nested Diagnostics Contexts (NDC) are designed to accomplish. So I
modified the event handlers in the Global.asax.cs file.
protected void Application_AuthenticateRequest(Object sender , EventArgs e) {
if ( Objects.User.Current != null )
NDC.Push("UserRequest: " + Objects.User.Current.Email) ;
else
NDC.Push("No User is logged in.") ;
}
protected void Application_EndRequest(Object sender , EventArgs e) {
NDC.Pop() ;
}
Now every log entry will include who the logged in user (or nobody). Weee!
One more thing: I was tired of typing the location of the message into the
message whenever I created a log entry. log4net is capable of recording the
code location for you automatically for a non-trivial performance hit. As I
currently use it though, I am primarily making log entries when some
odd/error condition has occurred, and not very many log entries are recorded
from normal use. As this project is also still in development I’m
not concerned about the performance penalty right now.
Getting log4net set up to record this though turned out to be rather annoying.
The PatternLayout system is built so that certain keys are converted to usefull
data. However the
log4net manual doesn’t say what those keys are. The
mailing list archive on SF had some information, but overall not a
terribly good reference. This
Quick Start to Using Log4j was a bit more useful. Fortunately they are
the same between log4net and log4j (one of the things the mailing archive
confirmed for me). Here are the ones I wanted:
- %C - Fully qualified class name
- %M - Method name
- %F - File name
- %L - Line number
- %l - Shortcut for %F%L%C%M
The other trick was getting to them to go into the database. As Ryan showed
previously we are putting this information into a database through the
ADNetAppender. When configuring this you specify the DB CommandText to be used
to make a log entry, and you can define parameters to be available in that
command text. For a larger example see Ryan’s
walkthrough. I thought it would just be a matter of defining a
couple new parameters, which it was, but it turned out the new parameters
needed to have a different syntax. So whereas the message parameter is defined
like:
<parameter>
<parameterName value="@message" />
<dbType value="String" />
<size value="4000" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%m" />
</layout>
</parameter>
The ClassName parameter needs to be defined like:
<param name="Parameter">
<param name="ParameterName" value="@ClassName" />
<param name="DbType" value="String" />
<param name="Size" value="512" />
<param name="Layout" type="log4net.Layout.PatternLayout">
<param name="ConversionPattern" value="%C" />
</param>
</param>
WTF?!? Why the two different syntaxes? When I tried to declare the ClassName
parameter similar to the message parameter, it would just use the message value
for each of the new parameters… yes I did check that the ConversionPattern
values were set correctly. It didn’t work until I used this alternate
syntax, at which point it worked perfectly. The original syntax comes
from the example
configuration files section of the log4net
documentation. Elsewhere they use the alternate syntax.
You’ve gotta love that gem of XML too, <name>Value</name> just
wasn’t verbose enough. Because, you see, this is a <param
name=”Parameter”> we are defining!
I do like log4net and I’m glad it’s there, good job developer people for
making a good, free, open, logging solution. But seriously, WTF?