Microsoft Enterprise Library Logging Block compared to Log4net

Microsoft recently released 1.0 of the Enterprise Library. I was curious how the Logging block stacked up to Log4net.

Pros

  • Configuration tool in the box - Slick little general purpose configuration tool used to configure all of the blocks in a consistent manner.
  • Active development community - There's lots of buzz around the new MS library, unlike Log4net which is "incubating" over at apache with no releases since Beta 8 in 2003-07-15 ! (The Log4net developers need to get a release out...like...yesterday hint hint). Additionally there is Microsoft backing for Enterprise Library which can be considered a positive for the future of the library.

Cons

  • No hierarchical configuration of categories - A nice feature of Log4net to be able to configure an entire hierarchy of loggers (if they are consistently named with dot delimited names) with a single switch rather than having to be explicit about every one. See Log4net's manual on Logger Hierarchy
  • The tool restarts the web app on configuration change - When using logging in an ASP.NET web application, the configuration tool re-writes the web.config when you save configuration changings. This restarts the web app even though the changes were limited to the two logging configuration files that are external to web.config. Ideally you should be able to change log settings "in-flight" without restarting the web site, and rewriting the web.config seems to defeat the purpose of the file-watching that reconfigures itself when changes occur to these external configuration files. This is easy to work around by just editing the files by hand, but that sort of defeats the purpose of having a tool.
  • No call-point short circuiting - There isn't a way to quickly determine whether logging is enabled at the call point to avoid unnecessary string building. It can be a big waste of time to concatenate or String.Format a large message string if it ultimately isn't going to be logged anywhere. See Log4net's FAQ for more information  Log4net lets me write:

if (log.IsDebugEnabled)
{
    log.Debug("Entry number: " + i + " is " + entry[i]);
}

  • Priorities - This is minor, but I would have liked to see an enumeration of standard priorities in the block. The Priority parameter is just an arbitrary int. I guess this good and bad...good because you can choose any priority scheme you want, bad because it will be harder to enforce consistency among all developers (For example - 0 = Verbose for one group and 1 = Verbose for another.) You can't use System.Diagnostics.TraceLevel because the method of filtering on "MinimumPriority" is reversed, lower numbers are more verbose for zEntLib, higher numbers are more verbose for TraceLevel.
  • Log4net appears to be much faster - In my testing, performance of the Enterprise Logging block was much slower than Log4net. Both on warm up time (the time it takes to configure the logging system and send the first log statement), and on logging 10000 messages in a tight loop.
  Enterprise Library Log4net
Warmup Time 3014 - 5107 milliseconds 100 - 161 milliseconds
Log 10000 messages 9624 - 9814 milliseconds 10 - 30 milliseconds

Testing methodology - I wrote two equivalent empty appenders, one for Log4Net, and one for EntLib that do nothing but retrieve the log message into a string variable. This was done to completely factor out the cost of the appender, and hopefully measure the performance overhead of the logging framework itself. Then I wrote a console application that measures the warm up time and the time it takes to log 10000 messages in a tight loop. You can download the Visual Studio 2003 test solution from here I'd love to know if I've made an incorrect assumption in my test.

26 Comments

  • Check out Log4net Viewer.

    Log4Net Viewer is a GUI log viewer and filter for the Log4Net library. By default it listens for LoggingEvent objects sent using the UdpAppender and displays them in a table.



  • I did run installutil.exe prior to running the tests. I should run installutil again just to be absolutely sure and rerun the test. I will correct the post if this causes a change in performance.

  • Was this test done against Microsoft's Enterprise Instrumentation Framework or just the logging application code block?

  • Nice post. We were leaning towards using the Enterprise library logging block, but may reconsider given the performance difference between the MSFT flavor and log4net.

  • Nice writeup. I was going to make the mistake of trying Microsoft's library. The webapp restart is a huge no-no. We're good with log4net for now.

  • The LogEntry is filled with all possible contents one could want to log every time even if there is no appender. I guess this is the biggest difference compared to log4net where the formatter will take the info on a need to format basis.

  • Here are my thoughts on the performance comparison:

    1. InstallUtil makes little or no difference. Without the assemblies installed, Entlib warmup/run time was ~4sec/~8sec, after running installutil (or more correctly InstallServices.bat in the src dir), the times were ~2.5sec/~8sec.

    2. I made EntLib logging slightly faster by calling the Write method with a precooked LogEntry object like below:

    <code>

    LogEntry entry = new LogEntry();

    for (int i=0; i<10000; i++)

    {

    entry.Message = "Message: "+i;

    Logger.Write( entry );

    }

    </code>

    Running that version takes the runtime down to around 5.5 seconds.



    Admittedly this is not really comparing 'like-for-like' usage against Log4Net, but it avoids the Write(string) command creating a new LogEntry object every time it is called. In a real world situation it might not be possible, with logging being called from different objects.

  • Thanks also for the hint.



    Just for brainstorm, no offence please.

    In the real life application, do you think you will log 10000 times in one shoot? Unless your code so buggy then you need high performance logger application. :)

  • Diamondo,

    You make a very valid point about the unrealistic test. And perhaps the follow-up question is how fast is fast enough for a logger? However when logging in a web application that has thousands of users, you can generate an awful lot of log messages. Especially if your code is well-instrumented with lots of debug tracing. It's very nice to leave debug tracing latent in the code ready to be turned on when something bad does happen that needs to be diagnosed. This is where EntLib's lack of call-point short-circuiting is particularly troubling to me because you incur a penalty for building up every log message even if you know it isn't going anywhere in production.



    And of course my code isn't that buggy, but um...I've heard that some people's code is :-), yeah that's it.

  • Not knowing the current level of logging at the time making the logging call(call-point short circuiting as you call) is big handicap for some applications like the one I am working on now, in which I need to serialize the messages that are sent out and received only when debug level is enabled. This is much more than a simple string builder.

  • Another thing I noticed with EntLib logging is everytime something is logged, a fresh instance of the sink is created, configured and used. Thus if one has a bunch of log stmts in an app, you can imagine the perf penality. IMHO, caching the sink would drastically improve the performance. Imagine openning the file for each log stmt.



    Ouch!!!



  • I think the results for EntLib in FireFox are a little different. Think Entlib startup in FireFox is a lot faster. Have not done any testing though but am mighty interrested if first observation is correct. I'm currently starting a new webapp and are thinking of using Entlib.

  • I just started looking at this portion of the EntLib a few hours ago. Although I have not used Log4Net, one of my first reactions was that something like log.IsDebugEnabled was missing.



    I've just started to dig through the source code, but wouldn't one option be to extend the library to include this sort of functionality?

  • Regarding web application restarts: You can avoid this from happening with EntLib. Before I tell you how I must subject you all to my two cents regarding this issue.



    ASP.NET chooses to recycle the web process when the config file changes. Frankly, I like this. I'm not changing config on the fly in production very often and when I do I like the idea of restarting my application's process. The last thing I want is multiple objects with a different config state because some config change hasn't been propogated accross my object graph yet (if at all). Now I've got different objects with different config states when I'm expecting the same config state.



    Now that that's off of my chest, EntLib's config block does support on the fly config changes without process recycles. The problem with using EntLib config with an ASP.NET application is that it overwrites the web.config each time you make a config change, even if that change doesn't affect the web.config. If you haven't made any specific changes to the configuration block (i.e., adding a new config section), then you can safely update the logging config files without updating your web.config. This will avoid the process recycle "problem". That is, unless something has changed since I've used the block :).

  • Loren,

    I was wondering if you happened to run your benchmark against Enterprise Library 2.0 and if the results were similar to those resported above.

  • Loren or others,

    Have you compared Log4net vs Logging Application Block 2.0

    any benchmarks?
    any features comparison?
    Scalability - 50 to 60 web servers
    Session Info filtering
    How to view Logs?
    and more ...

    Please !

    Sreedhar Vankayala
    vansree@yahoo.com

  • As part of .net 2.0 app block. You can shortcircuit the logging via the LogEnabled filter. Anyone know if the other cons were addressed as well?

    Thanks,
    Tim

  • can anybody tell what is the cause of error:

    System.InvalidCastException: Specified cast is not valid. at Createdatabase

  • I have a very basic question about both tools:

    Are they log asynchronously?
    I mean does the logging happen through a separate thread or it is processed by main working thread?

  • Log4Net definitely does not work with custom SharePoint 2007 workflows built with VS 2005. The issue seems be that the ILog object is not serializable, so once the workflow is dehyrdated to Sql Server, Log4Net stops honoring any logging calls. I don't know if EL 3.1 (May 2007) will work in its place.

  • I think Enterprise library 3.1 will definetly needs reviewing and checking

  • Link should be working again now.

  • just ran tests for log4net v1.2.10.0 vs EL4.0:

    C:\dotnet\LoggingProfile\LoggingDriver\bin\Release>LoggingDriver.exe log4net
    Log4Net
    Warmup time: 63 milliseconds
    Time to log 100000 messages: 109 milliseconds
    Press Enter to exit


    C:\dotnet\LoggingProfile\LoggingDriver\bin\Release>LoggingDriver.exe entlib
    EntLib
    Warmup time: 375 milliseconds
    Time to log 10000 messages: 2766 milliseconds
    Press Enter to exit

  • sorry, forgot to change the number to 100000 for entlib :) The correct output is:

    C:\dotnet\LoggingProfile\LoggingDriver\bin\Release>LoggingDriver.exe log4net
    Log4Net
    Warmup time: 63 milliseconds
    Time to log 100000 messages: 109 milliseconds
    Press Enter to exit

    C:\dotnet\LoggingProfile\LoggingDriver\bin\Release>LoggingDriver.exe entlib
    EntLib
    Warmup time: 312 milliseconds
    Time to log 100000 messages: 125344 milliseconds
    Press Enter to exit

  • I am developing webparts for huge MOSS project and Planning to implement logging.As per above discussions I came know Log4net is much faster than EntLib...Is it free tool?

  • Long past the initial discussion of this, but EntLib 4.1 (maybe earlier versions as well) features an Enabled check:

    "Logger.IsLoggingEnabled()"

Comments have been disabled for this content.