I thought nlog still had the Win32 api calls to coordinate the multiple process writing. I guess that changed at some point?
Now that there are potentially 3 classes that extend LockingModelBase we should move some of the duplicate code like SecurityContext.Impersonate into the base class and break apart some of the logic into new methods like CreateFileStream. While that is being done I think users would appreciate MinimalLock keeping a file open for a certain amount of time (seconds) then closing it. Maybe using a callback and a Timer that closes the file if nothing has been written to it for 5 seconds or so. That way the system can take advantage of exclusive lock performance. I believe nlog has this functionality. Patches are always welcome! I would encourage you (or others) to try not to just copy the nlog code verbatim. Let's try and make it better :-) https://issues.apache.org/jira/browse/LOG4NET It shouldn't be that hard to move the duplicate code from MutexLock, ExclusiveLock, and MinimalLock into LockingModelBase then add a couple additional methods like CreateFileStream. ----- Original Message ---- From: Steve Wranovsky <[EMAIL PROTECTED]> To: Log4NET User <log4net-user@logging.apache.org> Sent: Tuesday, January 22, 2008 6:06:35 PM Subject: Re: Log File Naming Problem 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 <log4net-user@logging.apache.org> > 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: log4net-user@logging.apache.org > > 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 > > > > > > > > > > > >
