[LOG4NET-454] Intermittent severe slowdown with RollingFileAppender+MinimalLock

• Type: Bug
• Status: Open
• Priority: Major
• Resolution: Unresolved
• Affects Version/s: 1.2.13
• Component/s: Appenders
• Environment: ASP.NET MVC 5.2.2 Application, Windows 7 Professional
• Assignee: Unassigned
• Reporter: Chuck Felish
• Created: 27/Feb/15 23:15
• Updated: 04/Apr/20 22:28

Description

Using RollingFileAppender with MinimalLock we found an extreme slowdown in the processing of our application requests (from 300ms to up to 15s in some cases) which was resolved when we deleted our log files. We also found that changing the lock to Exclusive resolved the issue.

Interestingly file content seemed to be related, but not file size. When I took the contents of a colleague's log file and pasted them into my own log file the slowness issue appeared again. I then tried deleting about half the contents and then causing the file to grow to larger than the original size but the issue did not return. Pasting the original contents back into the file caused the performance issue to return.

While Exclusive lock has resolved our issue for now, it's quite unexpected that file contents would affect performance at all, and that the issue is does not consistently reproduce even though configuration is unchanged.

I'm happy to demonstrate and/or share our problematic log files with you to facilitate the resolution of this issue.

Our configuration is as follows:

<appender name="RollingFile" type="log4net.Appender.RollingFileAppender">
<file type="log4net.Util.PatternString" value="Logs%property

{ExecutableName}

_%env

{COMPUTERNAME}

.log" />
<lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
<appendToFile value="true" />
<rollingStyle value="Size" />
<maximumFileSize value="5MB" />
<maxSizeRollBackups value="50" />
<preserveLogFileNameExtension value="true" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%d

{yyyy-MM-dd HH:mm:ss.fff}

[%-5level][%5thread] %logger - %m%n" />
</layout>
</appender>

<root>
<!-- NOTE: This is overriden programatically by Log4NetConfig.cs -->
<level value="ALL" />
<!-- <appender-ref ref="ColorConsole" />-->
<appender-ref ref="RollingFile" />
</root>

Issue Links

• relates to: LOG4NET-421 Inclusion of UserName in composite properties dictionary has a significant performance impact
• relates to: LOG4NET-429 Pattern with Context property causes severe slowdown