Ron,
On your suggestion, I went ahead and created a new MutexLock locking
model within the FileAppender. I made it so the OpenFile() method
opens the file in a shared write mode, and then I made AcquireLock and
ReleaseLock use a named Mutex (based on the filename), in an effort to
block concurrent writes to the log file across the app domains. I
took a small section of code from NLog for naming the Mutex, so its
based on the complete path of the log file name.
With these changes, I discovered one hole, the logging mechanism does
not seek to the end of the file each time it writes. Since I am
keeping the file open in each process, there may be other writes to
the file when I don't have the lock. Because of this, in
LockingStream.AcquireLock(), I added some simple code to seek to the
end of the file, after a lock is acquired on the file like this:
if (m_realStream.CanSeek)
m_realStream.Seek(0, SeekOrigin.End);
So, after these changes, it appears that my problem is resolved, I can
now log from multiple app domains, without any conflicts. Just as an
FYI, I had one other issue when testing the code: In some cases,
after the stream is locked, the code actually closes the file before
releasing the lock. I guess I'm up in the air, but it seems like you
might want to release the lock, then close the file.
In any case, below is the code I wrote. Feel free to use it if you want.
Steve
public class MutexLock : LockingModelBase, IDisposable
{
private string m_filename;
private bool m_append;
private bool m_mutexLocked = false;
private Stream m_stream = null;
private Mutex m_mutex;
private static string GetMutexName(string fileName)
{
string canonicalName = ConvertToFullPath(fileName).ToLower();
canonicalName = canonicalName.Replace('\\', '_');
canonicalName = canonicalName.Replace('/', '_');
canonicalName = canonicalName.Replace(':', '_');
return "filelock-mutex-" + canonicalName;
}
/// <summary>
/// Prepares to open the file when the first message is logged.
/// </summary>
/// <param name="filename">The filename to use</param>
/// <param name="append">Whether to append to the file, or
overwrite</param>
/// <param name="encoding">The encoding to use</param>
/// <remarks>
/// <para>
/// Open the file specified and prepare for logging.
/// No writes will be made until <see cref="AcquireLock"/>
is called.
/// Must be called before any calls to <see cref="AcquireLock"/>,
/// <see cref="ReleaseLock"/> and <see cref="CloseFile"/>.
/// </para>
/// </remarks>
public override void OpenFile(string filename, bool
append, Encoding encoding)
{
m_filename = filename;
m_append = append;
if (m_stream == null)
{
try
{
using
(CurrentAppender.SecurityContext.Impersonate(this))
{
// Ensure that the directory structure exists
string directoryFullName =
Path.GetDirectoryName(m_filename);
// Only create the directory if it does not exist
// doing this check here resolves some
permissions failures
if (!Directory.Exists(directoryFullName))
{
Directory.CreateDirectory(directoryFullName);
}
FileMode fileOpenMode = append ?
FileMode.Append : FileMode.Create;
m_stream = new FileStream(filename,
fileOpenMode, FileAccess.Write, FileShare.ReadWrite);
m_append = true;
}
}
catch (Exception e1)
{
CurrentAppender.ErrorHandler.Error("Unable to
open file " + m_filename + ". " + e1.Message);
if (m_stream != null)
{
m_stream.Close();
m_stream = null;
}
}
}
}
/// <summary>
/// Close the file
/// </summary>
/// <remarks>
/// <para>
/// Close the file. No further writes will be made.
/// </para>
/// </remarks>
public override void CloseFile()
{
using (CurrentAppender.SecurityContext.Impersonate(this))
{
if (m_stream != null)
m_stream.Close();
m_stream = null;
}
}
/// <summary>
/// Acquire the lock on the file
/// </summary>
/// <returns>A stream that is ready to be written to.</returns>
/// <remarks>
/// <para>
/// Acquire the lock on the file in preparation for writing to it.
/// Return a stream pointing to the file. <see cref="ReleaseLock"/>
/// must be called to release the lock on the output file.
/// </para>
/// </remarks>
public override Stream AcquireLock()
{
if (m_mutex == null)
{
m_mutex = new Mutex(false, GetMutexName(m_filename));
m_mutexLocked = false;
}
if (m_stream == null)
{
OpenFile(m_filename, m_append, Encoding.Default);
if (m_stream == null) return null;
}
m_mutex.WaitOne();
m_mutexLocked = true;
return m_stream;
}
/// <summary>
/// Release the lock on the file
/// </summary>
/// <remarks>
/// <para>
/// Release the lock on the file. No further writes will
be made to the
/// stream until <see cref="AcquireLock"/> is called again.
/// </para>
/// </remarks>
public override void ReleaseLock()
{
if (m_mutex != null)
{
m_mutexLocked = false;
m_mutex.ReleaseMutex();
}
}
public void Dispose()
{
if (m_mutex != null)
{
if (m_mutexLocked)
m_mutex.ReleaseMutex();
m_mutex.Close();
m_mutex = null;
}
if (m_stream != null)
m_stream.Close();
m_stream = null;
}
}
On Jan 21, 2008 11:41 AM, Ron Grabowski <[EMAIL PROTECTED]> wrote:
> Maybe instead of the MinimalLock you could write a MutexLock locking model in
> conjunction with opening the file in more of a shared mode so each plugin has
> write permission to the file but the mutex (either at the locking model level
> or inside a special MutexFileAppender) is the gatekeeper for file writes. I
> think the biggest challenge is the rolling file appender requirement. Can you
> configure the host to use a FileAppender that writes to the current day's log
> file? I recall nlog has some special ways to deal with multiple processes
> writing to the same file. It uses Win32 apis to cooridnate multiple writes. I
> would imagine this is much much faster than the MinimalLock model. I've not
> tried nlog's multiprocess write support in conjunction with rolling the file.
>
> I've not done a lot with plugins and app domains but I think making the host
> responsible for receiving/recording log messages from the plugins seems like
> a more managable solution. You don't want a plugin to mess up the log file
> for the host.
>
> ----- Original Message ----
> From: Steve Wranovsky <[EMAIL PROTECTED]>
>
> To: Log4NET User <[email protected]>
> Sent: Monday, January 21, 2008 11:08:40 AM
> Subject: Re: Log File Naming Problem
>
>
> First, concerning our use of multiple App domains, we've implemented a
> plugin based Windows service that has several independently running
> plugin threads running. We've decided to use an App domain per plugin
> thread so that if there is a problem with one of the plugins/threads,
> it doesn't bring down the other threads within the service.
>
> I took a look at the blog post, and our code is similar to what is
> described in that post. We are initializing log4net in each app
> domain. We potentially have a very large amount of logs being
> generated overall in our system. I'd prefer to avoid having to save
> the data in a database, so routing the logs to a single
> RollingFileAppender seems to be the best solution. It sounds like
> this would also be an added benefit from a performance standpoint if
> we were able to use the ExclusiveLock locking model.
>
> Thanks for the feedback. It would be nice if this worked with the
> standard RollingFileAppender, but, this at least points me in a
> direction to find a solution to the problem I am having.
>
> Steve
>
>
> On Jan 20, 2008 1:42 PM, Ron Grabowski <[EMAIL PROTECTED]> wrote:
> > When a new app domain is created is log4net re-initialized in the new
> app domain?
> >
> > It sounds like the problem is that you have a lot of threads trying
> to open, close, and roll the log file. Can you delegate all the locking
> issues to a database then extract data out at a later date?
> >
> > If using a database isn't an option I suggest trying to route all the
> messages to a single RollingFileAppender instance configured to use
> the default ExclusiveLock locking model (MinimalLock is noticeably slower
> even for a small amount of logs). A comment from this blog:
> >
> >
>
> http://www.jasonbock.net/JB/Default.aspx?blog=entry.f48ab22438bc4e35969ca6c559763e9c
> >
> > mentions using Remoting to channel all the messages from the threads
> to a single RollingFileAppender so there is a single thread and class
> controlling rolling. You coculd use the IpcChannel for inter-process
> communications. Is your code similiar to the sample code in the blog post?
> >
> > If you don't mind me asking, what is the use case for having to
> create new app domains in addition to the new threads?
> >
> >
> > ----- Original Message ----
> > From: Steve Wranovsky <[EMAIL PROTECTED]>
> > To: [email protected]
> > Sent: Thursday, January 17, 2008 11:10:29 AM
> > Subject: Log File Naming Problem
> >
> >
> > Hello,
> >
> > I have a multi-threaded application using log4net 1.2.10 for logging.
> > There are a couple of points when the application runs where there
> are
> > a large number of logs occurring simultaneously from multiple threads
> > (that happen to be in different App Domains). On occasion, I will
> end
> > up with two separate log files generated when this point in my
> > application occurs. One of the log files will end up with a date
> > pattern twice in the name and will look something like this:
> >
> > Server_2008-01-16.log
> > Server_2008-01-16.log2008-01-16.log
> >
> > A few of the logs end up in the second log file from one of the
> > threads. The remainder of the threads log to the first log file and
> > continue using it. Occasionally this second log file will be used
> > again by another thread if the problem happens again. Here's the
> > configuration file I'm using:
> >
> > <log4net>
> > <appender name="RollingLogFileAppender"
> > type="log4net.Appender.RollingFileAppender">
> > <param name="File"
> > value=".\\logs\\Server_" />
> > <param name="AppendToFile"
> value="true"
> > />
> > <param name="MaxSizeRollBackups"
> > value="20" />
> > <param name="MaximumFileSize"
> > value="10MB" />
> > <param name="RollingStyle"
> > value="Composite" />
> > <param name="datePattern"
> > value="yyyy-MM-dd.lo\g" />
> > <param name="StaticLogFileName"
> > value="false" />
> > <layout
> > type="log4net.Layout.PatternLayout">
> > <param
> > name="ConversionPattern" value="%d [%t] %-5p - %m%n" />
> > </layout>
> > <lockingModel
> > type="log4net.Appender.FileAppender+MinimalLock" />
> > </appender>
> > <root>
> > <level value="INFO" />
> > <appender-ref
> > ref="RollingLogFileAppender" />
> > </root>
> > </log4net>
> >
> > It appears that perhaps a lock is failing in one of the threads, and
> > it by default tries to create another log file to log to. Is it
> > possible to block this from happening and have the logs go into the
> > original log file? If this is not possible, it would be nice if the
> > second log file didn't have the double date in it, or if the handling
> > of this was cleaner.
> >
> > Thanks,
> > Steve
> >
> >
> >
> >
>
>
>
>
