Tuesday, August 11, 2009

log4net and IIS Web clusters

We use log4net quite a bit at my current job. One of the ASP.Net applications is deployed to a web-cluster so that it has a high degree of availability. But for some reason, on this app, we seemed to be loosing some events that we knew were occurring (log4net was sending emails of the events but not writing them to the log file). This continued for a while without us making any kind of a head way in figuring out the problem. And then we got our first clue when we included the computer name as part of the information that log4net was writing out (${COMPUTERNAME} in the ConversionPattern). We found that events from only one computer were ever being written to the log file and it always was the first one where the application restarted.

This pointed to a file locking issue. And sure enough, log4Net, opens the log file with an exclusive lock when it opens a file for writing (for file based appenders such as the RollingLogFileAppender).

Here are the 2 attributes that I included on my file based appenders to get around the issue:

<immediateFlush>true</immediateFlush>
<lockingModel type="log4net.Appender.FileAppender+MinimalLock"/>

The first one makes sure that the log is written out immediately and the second one makes sure that log4net does not open a log file exclusively.

A word of warning – both of these options will increase the amount of time log4net uses to write to the log (as no buffering takes place and each time the log is written to, log4net opens, writes and then closes the file). In our application, I havent found this to increase response time of the application significantly.

1 comment:

Adam said...

Thanks for the tip, we haven't come across this particular issue yet, but I know we will!