Click here to Skip to main content
Click here to Skip to main content

Tagged as

Logging into single file from multi-process

, 2 Jun 2008 CPOL
Rate this:
Please Sign up or sign in to vote.
This article shows a way to logging into single logfile from multi-process avoiding file lock conflict

Introduction

When you want to log from multisource into single log using log4net, the theory is using AdoNetAppender or EventLogAppender.

But if it's hard to use Databases , EventLog, syslog and so on. Here is the way to logging into single logfile from mutli-process runnning concurrently.

Problem

The problem of using Fileappender from processes runnning concurrently is file lock confilict.
When the first process gets write lock for logfile, any other process can't get write lock for logfile and can't write a LogEntry into logfile.

log4net has a solution for this problem, it's called MinimalLock locking model.
In this locking model, log4net gets write lock when the looger write LogEntry into logifile, and release lock once LogEntry is logged.
So this locking model holds lock for minimal time, it's reduce the conflicts but not eliminate.

I extends Minimallock and eliminate conflict.

Solution

The concept is,
1. Caching LogEntry into cache instead of writing into file directory.
2. Dequeue and writing into file in new thread.
3. When Confilict is detected, wait random time and retry.

public class ConcurrentMinimalLock : FileAppender.MinimalLock
 {
  private string m_filename;
  private bool m_append;
  private Stream m_stream=null;
  private ConcurrentStream c_stream = null;
  public override void OpenFile(string filename, bool append, Encoding encoding)
  {
   m_filename=filename;
   m_append=append;
  }
  public override void CloseFile()
  {
   // NOP
  }
  public override Stream AcquireLock()
  {
   if (m_stream==null)
   {
    try
    {
     using(CurrentAppender.SecurityContext.Impersonate(this))
     {
      string directoryFullName = Path.GetDirectoryName(m_filename);
      if (!Directory.Exists(directoryFullName))
      {
       Directory.CreateDirectory(directoryFullName);
      }
      
      if(c_stream == null)
      {
       c_stream = ConcurrentStream.GetInstance(m_filename, m_append, FileAccess.Write, FileShare.Read);
      }
      m_stream = c_stream;
      m_append=true;
     }
    }
    catch (Exception e1)
    {
     CurrentAppender.ErrorHandler.Error("Unable to acquire lock on file "+m_filename+". "+e1.Message);
    }
   }
   return m_stream;
  }
  public override void ReleaseLock()
  {
   using(CurrentAppender.SecurityContext.Impersonate(this))
   {
    m_stream.Close();
    m_stream=null;
   }
  }
 }

First, I extends MinimalLock Class and Replace stream with ConcurrentStream

public class ConcurrentStream : Stream
 {
  private string path;
  private bool append;
  private FileAccess access;
  private FileShare share;
  private QueueManager queueManager;
  private static ConcurrentStream instance;
  
  public static ConcurrentStream GetInstance(string path,
   bool append,
   FileAccess access,
   FileShare share)
  {
   if(instance == null)
   {
    instance = new ConcurrentStream(path,append,access,share);
   }
   return instance;
  }
  private ConcurrentStream (
   string path,
   bool append,
   FileAccess access,
   FileShare share
   )
  {
   this.path = path;
   this.append = append;
   this.access = access;
   this.share = share;
   this.queueManager = QueueManager.GetInstance(path,append,access,share);
  }

  public override void Write(byte[] buffer, int offset, int count)
  {
   CachedEntry entry = new CachedEntry(buffer,offset,count);
   queueManager.Enqueue(entry);
  }
 }

Next, Create ConcurrentStream Class extending Stream.
Write method doesn't write directly, instead write information into queue.

internal class QueueManager
 {
  
  private string path;
  private bool append;
  private FileAccess access;
  private FileShare share;
  
  private Queue syncQueue = Queue.Synchronized(new Queue());
  
  private bool running = false;
  private Random rnd = new Random();
  private DateTime retryTime = DateTime.MaxValue;
  
  private static TimeSpan RETRY_MAX_SPAN = TimeSpan.FromMinutes(1);
  private static QueueManager instance;
  private const int MAX_BATCH_SIZE = 100;
  
  
  public static QueueManager GetInstance(string path,
            bool append,
            FileAccess access,
            FileShare share)
  {
   if(instance == null)
   {
    instance = new QueueManager(path,append,access,share);
   }
   return instance;
  }
  private QueueManager(
   string path,
   bool append,
   FileAccess access,
   FileShare share)
  {
   this.path = path;
   this.append = append;
   this.access = access;
   this.share = share;
  }
  internal void Enqueue(CachedEntry entry)
  {
   syncQueue.Enqueue(entry);
   
   if(!running)
   {
    lock(this)
    {
     running = true;
     Thread th = new Thread(new ThreadStart(this.Dequeue));
     th.Start();
    }
   }
  }
  private void Dequeue()
  {
   CachedEntry entry =null;
   try
   {
    using(FileStream fs = new FileStream(path,FileMode.Append,access,share))
    {
     int processedCount = 0;
     while(true)
     {
      processedCount ++;
      if(syncQueue.Count == 0)
      { 
       //quit when queue is empty
       lock(this)
       {
        running = false;
        return;
       }
      }
      else
      {
       entry = (CachedEntry) syncQueue.Dequeue();
      }
  
      if(entry !=null )
      {
       Write(entry,fs);
      }
     }
    }
   }
   catch(IOException ioe)
   {
    if(DateTime.Now - retryTime > RETRY_MAX_SPAN)
    {
     lock(this)
     {
      running = false;
     }
     throw;
    }
    //When can't aquire lock
    //Wait random time then retry
    Thread.Sleep(rnd.Next(1000));
    Console.WriteLine("Retry:" + DateTime.Now);
    retryTime = DateTime.Now;
    Dequeue();
   }
  }
  private void Write(CachedEntry entry,FileStream fs)
  {
   fs.Write(entry.Buffer,entry.Offset,entry.Count);
   fs.Flush();
  }
 }

And above is the queue implementation.
When logentry is enqued, dequeue is runnnin on new thread.
When the conflict occurs, wait random and then retry.(like CSMA/CD)

Thus, we can make multi-process logging successsully.

internal class CachedEntry
 {
  private byte[] buffer;
  private int offset;
  private int count;
  internal byte[] Buffer
  {
   get{return buffer;}
  }
  internal int Offset
  {
   get {return offset;}
  }
  internal int Count
  {
   get {return count;}
  }
  internal CachedEntry(byte[] buffer, int offset, int count)
  {
   this.buffer = new byte[buffer.Length];
   buffer.CopyTo(this.buffer,0);
   this.offset = offset;
   this.count = count;
  }
 }

Finally, above is the entry queued.

And cofiguration file looks like below

<configuration>
 <configSections>
  <section name="log4net" type="System.Configuration.IgnoreSectionHandler" />
 </configSections>
 
 <log4net>
  <appender name="AppenderTest" type="log4net.Appender.FileAppender">
   <param name="File" value="C:\\temp\\logtest.txt" />
   <param name="AppendToFile" value="true" />
   
   <param name="LockingModel" type="ConcurrentLog.ConcurrentMinimalLock,ConcurrentLog"/>
   
   <layout type="log4net.Layout.PatternLayout">
    <param name="ConversionPattern" value="%d [%t] %-5p - %m%n" />
   </layout>
  </appender>
  
  
  <logger name="LoggerTest">
   <level value="DEBUG" />
   <appender-ref ref="AppenderTest" />
  </logger>
  
 </log4net>
</configuration>

License

This article, along with any associated source code and files, is licensed under The Code Project Open License (CPOL)

Share

About the Author

Masayuki Tanaka
Software Developer
Japan Japan
I am Software Developer currently working at global IT consulting firm in Tokyo, Japan.
 
I have 9 years of experience in software development especially in Web Application.
 
I want to improve my English writing and speaking skill.
So,I am looking for English - Japanese language exchange partner in Tokyo area.
If you have some interest, Please email me<m-tanaka@pp.iij4u.or.jp>.

Comments and Discussions

 
QuestionNeed Source Code PinmemberMember 1043343313-Feb-14 20:07 
SuggestionLogging to multiples files Pinmembergjmv18-May-12 8:46 
GeneralNeed some clarifications PinmemberJohn JB1-Jun-11 20:59 
Generalretry timeout issue PinmemberPatrik Hartlén16-Nov-09 2:10 
Questionperformance Pinmembershveik29-Jul-08 8:36 
GeneralSource code [modified] Pinmembermlhmlh24-Jul-08 4:42 
QuestionSource Code Pinmemberjslaybaugh24-Jun-08 9:48 
QuestionWhy this improvement? PinmemberMartin.Holzherr3-Jun-08 5:34 
AnswerRe: Why this improvement? PinmemberMasayuki Tanaka4-Jun-08 5:30 
GeneralInformative, but one query. Pinmemberdnpro3-Jun-08 1:46 
GeneralRe: Informative, but one query. PinmemberMasayuki Tanaka4-Jun-08 5:13 
JokeVery Good job, it must be included into log4net PinmemberFrancisco Moreno10-Jun-08 1:12 

General General    News News    Suggestion Suggestion    Question Question    Bug Bug    Answer Answer    Joke Joke    Rant Rant    Admin Admin   

Use Ctrl+Left/Right to switch messages, Ctrl+Up/Down to switch threads, Ctrl+Shift+Left/Right to switch pages.

| Advertise | Privacy | Terms of Use | Mobile
Web02 | 2.8.141223.1 | Last Updated 2 Jun 2008
Article Copyright 2008 by Masayuki Tanaka
Everything else Copyright © CodeProject, 1999-2014
Layout: fixed | fluid