I've got a C# DLL that is used from a number of different places, including .Net EXEs, VB6 EXEs, Work and Outlook COMAddIns and also Outlook forms. It uses log4net for tracing and debugging.
I'd found log4net to be pretty reliable BUT sometimes messages weren't ending up in my log file (usually when I really needed them!). Most recently this happened today when I was trying to trace a problem in my Outlook form. I'd drag the appointment in Outlook which would fire the Item Write event on the form and, although I could loo kin the DB and see that my DLL was working, nothing was showing up in the log4net log file.
How to Investigate the Problem
To find out what was really happening, I used log4net's internal debugging. In the case of an Outlook Form, I switched it on like this:
- Started Outlook
- Started Visual Studio and opened my DLL project
- Switched on log4net internal debugging by modifying my log4net configuration file and changed the <log4net> to read <log4net debug="true">
- Used "Tools-Attach to Process" and attached to the Outlook.exe process
- Placed a breakpoint in the project on a line that I knew it should encounter
- Ran the test again...
The Problem
When I ran the test again with log4net debugging switched on, I could clearly see that log4net was unable to write to my logfile because it was locked. I didn't obviously have it locked (I had it open in TextPad but closing that didn't fix the problem). A quick scout around revealed that log4net with the RollingFileAppender by default will lock the file and keep it locked. Clearly this was the problem in my case where multiple programs all use my DLL which writes to the same logfile.
The Solution
I do want all of the instances of my DLL to write to the same log file, but I don't want them to lock the file and keep each other out. The solution was to add the following to the appender section of my log4net configuration file:
<lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
This instructs log4net to get the lock, write and release the lock every time - so it doesn't keep the file locked. With this in place, all of my DLL instances now write to the logfile, ALL of the time! There is a slight performance overhead to this approach, but then I'd rather than it works slowly, than not working quickly!
