Something is wrong with Log4Net?

Question

I've been using Log4Net on a few high traffic websites for a couple of years, and I cannot say that I am a happy customer. So, wanted to see if anybody else has the same concerns:

1. The CPU overhead with RollingFileAppendor is massive. Some of my websites need to trace 5-10GB per day, and when I enable logging, the CPU utilization more than doubles. I would like to avoid the discussion of why so much tracing is needed. Some mission critical apps have to trace every step of every transaction.

2. Rolling by date is often unreliable (it logs fine during the day, but then messes up the last day's log file around midnight). This behavior is inconsistent. I've seem more than a few people online that complain on this and nobody seems to have a good solution.

3. Last but not least, I have not seen any new releases on the Apache website during the last three years. So, this starts to look as an abandoned open source project, and that usually means that it's time to move on to some alternative framework.

So, I am considering giving up Log4Net in favor of the Microsoft Enterprise Library or something else. Is anybody here having the same issues as me?

Answer 1

So, I am considering giving up Log4Net in favor of the Microsoft Enterprise Library or something else.

For a comparison of alternative logging frameworks you might want to consider, see http://essentialdiagnostics.codeplex.com/wikipage?title=Comparison

It compares .NET Framework System.Diagnostics (built in capabilities), log4net, NLog and Enterprise Library, including a performance comparison.

Each has strengths and weaknesses, but EntLib does particularly bad on the performance comparison and, in terms of features, sometimes has less that the built in .NET Framework System.Diagnostics.

If you are particularly concerned about performance then log4net wins slightly with the .NET Framework System.Diagnostics similar.

NLog has very little overhead when not logging (i.e. just leaving it in the code), faster than either log4net or System.Diagnostics, but as the logging volume increases starts to fall behind.

For high performance logging using System.Diagnostics, with log rotation (including circular), have a look at the EventSchemaTraceListener, which I recently blogged about, but the tool support for viewing the logs (which are in an XML format) isn't very good.

I'd suggest you set up some performance testing if you are concerned. For the comparison listed above the source code of the performance comparison is available in the Essential Diagnostics project, so you can run it yourself, but you might want to tailor to your situation.

Answer 2

For the performance issue the great thing about log4net is that you can always profile it to see where your application usage of log4net is bottlenecked and either: 1) Tackle the solution yourself or 2) Find a logging framework that doesn't have that bottleneck.

I can't help too much without knowing your application but from a cursory glance at the log4net source I noticed that the NextCheckDate() function is being called on EVERY void Append(LoggingEvent loggingEvent). I've included a portion of the source for NextCheckDate below and I could definitely picture this causing performance problems in high-volume logging scenarios.

protected DateTime NextCheckDate(DateTime currentDateTime, RollPoint rollPoint){
// Local variable to work on (this does not look very efficient)
DateTime current = currentDateTime;

// Do different things depending on what the type of roll point we are going for is
switch(rollPoint) 
{
    case RollPoint.TopOfMinute:
        current = current.AddMilliseconds(-current.Millisecond);
        current = current.AddSeconds(-current.Second);
        current = current.AddMinutes(1);
        break;

    case RollPoint.TopOfDay:
        current = current.AddMilliseconds(-current.Millisecond);
        current = current.AddSeconds(-current.Second);
        current = current.AddMinutes(-current.Minute);
        current = current.AddHours(-current.Hour);
        current = current.AddDays(1);
        break;

    case RollPoint.TopOfMonth:
        current = current.AddMilliseconds(-current.Millisecond);
        current = current.AddSeconds(-current.Second);
        current = current.AddMinutes(-current.Minute);
        current = current.AddHours(-current.Hour);
        current = current.AddMonths(1);
        break;
}     
return current;}

An optimized version for your application would probably cache the next rollover time in advance and only do a single comparison for each Append

Answer 3

So far, I am inclined to blame everything on date-based rolling feature. I've tried swapping it for size-based rolling on a few servers, and I no longer see any data losses. Of course, this is not a pretty workaround because I no longer have one trace file per day. Also, the size-based rolling seems to have a bug that causes the file to roll either way too early or way too late. But this is not as painful as the original problem...

Answer 4

May be it's not your case, but I think that with such volumes of log data you should be using log management system which has zero or minimal effect on your actual application during run time. Rolling around and managing gigabytes of log is rather awkward unless all your application does is create log. Another point - I've heard many complaints from users of entlib logging particularly regarding the performance. I'd check how it would do with your volumes of data before switching to it. But even if you do find it better than log4net, I think you will still be managing huge log files yourself.

Answer 5

1. Yes, it tends to use too much CPU. I had an app where I logged ~15GB/day and CPU usage was kind of high. I cut down logging to ~4GB/day, now the CPU usage is not noticeable at all.
2. I've never seen this behavior (and I've been using log4net since 1.1.1 (3 years) in high-traffic websites)
3. Yes, it's kind of quiet, but maybe that's because it's a stable, mature project. And development hasn't totally stopped, you can see in the svn repo that there's been some commits recently. If you're concerned about this, take a look at NLog, it's a younger, more active project.

Here's my appender config for comparison:

<appender name="LogFileAppender" type="log4net.Appender.RollingFileAppender, log4net" >
    <param name="File" value="log" />
    <param name="AppendToFile" value="true" />
    <rollingStyle value="Date" />
    <datePattern value="yyyyMMdd" />
    <maxSizeRollBackups value="7" />
    <layout type="log4net.Layout.PatternLayout, log4net">
        <param name="ConversionPattern" value="%d [%t] %-5p %c [%x] - %m%n" />
    </layout>
</appender>

Answer 6

You could look at using ASP.NET 2.0's Health Monitoring, and How To: Use Health Monitoring in ASP.NET 2.0

But I think you are going to have similiar problems. You are trying to use a logging tool as an audit tool, not exactly what it was designed for.

"Some mission critical apps have to trace every step of every transaction." - This is information that I would be logging to the database as part of a transaction. How could you guarantee the information is correct if it runs outside of a transaction?