Geeks With Blogs
On the Ledge The general evolution (and occasional regression) of a .NET developer

log4net is a great little logging library.  There seem to be some mixed results out there as to whether or not it outperforms the Enterprise Library's Logging Application Block, although it appears to me the general findings are that log4net is faster.  For me, I guess it would come down to how badly I wanted integration with the rest of the Enterprise Library.  If that's not a priority, log4net can be a lightweight, fast way to get logging going in your application.

Once you've got the library in your project, you can configure your loggers in web.config.  For example:

<log4net> 
  <logger name="Activity">
    <level value="ALL"/>
    <appender-ref ref="Activity_FileAppender"/>
  </logger>
  <logger name="Errors">
    <level value="ALL"/>
    <appender-ref ref="Error_FileAppender"/>
  </logger>
  <logger name="ElapsedTime">
    <level value="ALL"/>
    <appender-ref ref="ElapsedTime_FileAppender"/>
  </logger>
  <logger name="TimeOut">
    <level value="ALL"/>
    <appender-ref ref="TimeOut_SmtpAppender"/>
  </logger>

<appender name="Activity_FileAppender" type="log4net.Appender.RollingFileAppender">
  <file value="c:\Logs\Proxy_Activity.log" />
  <appendToFile value="true" />
  <rollingStyle value="Composite" />
  <datePattern value="yyyyMMdd" />
  <maxSizeRollBackups value="10" />
  <maximumFileSize value="10MB" />
  <layout type="log4net.Layout.PatternLayout">
    <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline" />
  </layout>
</appender>

... other appender configs ...

</log4net>

 

(I'm not going to do the color coding on all that)

So, you can get fairly fine-grained in your log4net configurations.  Emails, databases, etc. for your log events are configured also using an <appender>, just with some different nodes set.

In code, you simply instantiate a logger using the name you chose in your config, then use that to log messages.  I chose to create static instances in my classes so I could just re-use them:

protected static readonly ILog ActivityLog = LogManager.GetLogger("Activity");
protected static readonly ILog ErrorLog = LogManager.GetLogger("Errors");

And so on.  Both ILog and LogManager are part of log4net's API.

Once those are available, you can use them in your code according to the format string you put in your web.config for that logger.  You use different logging methods to assign different severity levels:

ActivityLog.Info(String.Format("Response sent for {0}: {1}", _requestId, response.BodyStr));

or

ErrorLog.Fatal(String.Concat("EXCEPTION: ", response), exception);

With this very simple setup, it was easy to insert logging statements into different areas of the Proxy's processing.  Since the Proxy was only a few classes and mostly procedural in operation, using Aspect-Oriented Programming to tie logging to methods and such wasn't the best way to go for this specific situation, although it probably is for most.

Regardless of how you actually call your logging functionality, you already have a quick setup and a nice decoupling of your log "publishers" from your logging calls, allowing you freedom to change where your log messages end up and add several "publishers" to the same logging call.  For example, our system timeouts are not only logged, but also emailed to an email box specifically set up to track timeout issues.

By doing this, we log the following points:

  • When a request comes in.
  • When preprocessing of that request begins.
  • When that request is forwarded to the system.
  • When a response is received from the system.
  • When the response is forwarded to the requestor.
  • The time differences between each point.
  • Any time an exception is thrown.
  • Any time a timeout occurs.

Once the setup was done, logging when and what we wanted was a piece of cake.  In fact, I could describe a good chunk of our release of the Proxy as, "Looks like it's running great!  Wait a minute.  Are you logging X?  Go back and add logging to X."  This happened at least ten times while we were deploying, and I was able to do it because it was so easy to modify the logging in such a short amount of time.

However, we still had a need for speed.  In my next post, I'll talk about how we used threads to make our logging to the database asynchronous.

Posted on Wednesday, September 23, 2009 10:42 AM How-To , Proxy | Back to top


Comments on this post: Logging with log4net

# re: Logging with log4net
Requesting Gravatar...
Very nice article, well written, clean and neat...
Left by MichaelL on Feb 09, 2010 9:20 AM

Your comment:
 (will show your gravatar)


Copyright © ledge | Powered by: GeeksWithBlogs.net