[Prev] Thread [Next]  |  [Prev] Date [Next]

[jira] Commented: (LOG4NET-175) RollingFileAppender generates unexpected filename and/or causes IIS to hang Devan Iyer (JIRA) Mon Sep 29 17:00:35 2008


Devan Iyer commented on LOG4NET-175:

I solved this one:

This behaviour is due to RollingFileAppender and it's base class FileAppender 
not resetting certain private member variables when an OpenFile call fails.

RollingFileAppender.OpenFile (filename, bAppend) always does a 
GetNextOutputFileName(fileName) before calling the base class OpenFile. This 
appends the string value of m_curSizeRollBackups to filename.


FileAppender.OpenFile (filename, bAppend) stores in private member variables 
the value of the arguments filename and bAppend and then attempts to create a 
LockingStream. This fails with a LockStateException which is not handled. The 
correct approach would be to roll back the values of m_fileName, m_appendToFile 
, m_curSizeRollBackups and m_scheduledFilename when the OpenFile call fails. I 
accomplished this in my subclass as follows:


    protected override void <MyClass>OpenFile(string fileName, bool append)
        bool oldAppend = this.AppendToFile;
        string oldFileName = this.File;


            base.OpenFile (fileName, append);
        catch (log4net.Core.LogException ex)
            LogLog.Debug ("CERollingFileAppender.OpenFile, base.OpenFile 
(fileName, append) threw an exception, " + ex.Message);
            base.File = oldFileName;    // easily set by protected property 
            base.AppendToFile = oldAppend;    // easily set by protected 
property access
            base.ExistingInit ();    // no access to m_curSizeRollBackups and 
m_scheduledFilename but this will do it.

Ideally this fix should be in the core RollingFileAppender, FileAppender 
implementations with appropriate additional configuration status checks.

> RollingFileAppender generates unexpected filename and/or causes IIS to hang
> ---------------------------------------------------------------------------
>                 Key: LOG4NET-175
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-175
>             Project: Log4net
>          Issue Type: Bug
>          Components: Appenders
>    Affects Versions: 1.2.9
>         Environment: win32
>            Reporter: Devan Iyer
>   Original Estimate: 2h
>  Remaining Estimate: 2h
> We are using rolling file appender in an IIS managed C# application. Our 
> log4Net deployment is configured with the following options specified in 
> basic.xml: <appendToFile value="false" /> <countDirection value="0" /> 
> <maximumFileSize value="512KB" /> <maxSizeRollBackups value="100" /> 
> <rollingStyle value="Once" /> <staticLogFileName value="false" />. The file 
> pattern for our log file name is "abc_%date{yyyyMMdd_HHmmss}_%processid_.log".
> We have observed in our production environment that occasionally filenames 
> would be created with patterns like 
> "abc_%date{yyyyMMdd_HHmmss}_%processid_.log.1", 
> "abc_%date{yyyyMMdd_HHmmss}_%processid_.log.1.2", 
> "abc_%date{yyyyMMdd_HHmmss}_%processid_.log.1.2.3", etc. We have observed 
> filenames with the dot+sequential numbers pattern after the .log to be 
> anything from ".1" to ".220". This is one of two unexpected behaviours 
> observed.
> The second unexpected behaviour seems to a special case of the first that 
> occasionally causes IIS to hang (100% CPU consumption). An analysis of 
> several crash dumps taken at the time of the hang indicated that 
> RollingFileAppender had in memory a filename of the same pattern as above but 
> with the number of characters [base filename pattern]+[recurring extension 
> pattern] exceeding 255 characters. It is very likely that an attempt to 
> create a file by such name on NTFS would throw exceptions at various levels - 
> managed and native - and hence the file itself is never created.
> To the best of our knowledge, there were no events to trigger the filename to 
> be rolled. As indicated in the configuration options, we are using 
> RollingStyle of "Once". (The log file content is minimal at the time the 
> symptoms occur - total file size is about 2K - and the times of occurrence 
> are totally non related).
> We have been unable to capture the workflow leading up to the symptoms above 
> due to the high number of users and document types in our production 
> environment. The permissions on the logging folder are static. However, we 
> have found a simple workflow in our lab environment, using permissions, that 
> produce similar symptoms. This workflow is:
> - Right click on the logging folder and select "Properties"
> - Under the "Security" tab ensure that IIS_WPG group doesn't have write 
> access to the logging folder.
> - Restart IIS
> - Launch our application and view a document.  Check the logging folder to 
> make sure that a logfile is not created.
> - View a few more documents
> - Change the permission on the logging folder and ensure IIS_WPG group has 
> write access to the folder.  DO NOT restart IIS after changing the permission.
> - Launch our application and view another document.
> - At this point a logfile with a filename pattern described will be found in 
> the logging folder.
> As mentioned, it is unlikely that permissions are the trigger in our event 
> but it is likely that the same code is creating these unexpected patterns 
> irrespective of the trigger.

This message is automatically generated by JIRA.
You can reply to this email to add a comment to the issue online.