We have a webservice that has been running on Windows 2008R2 since
Nov 2015 and has not had any issues until just a week or so ago. The
webservice becomes unresponsive and after installing some debug tools
I can see that we have a deadlock issue.
Here is some details of the last dump. Note we are running the
project under .NET 4 and have .NET 2 dependencies in the project that
depend on the .NET 2 1.2.11.0 version of log4net. I can see also on
the stack trace that we had a few exceptions happen and I assume the
blocking thread was attempting to roll our Exceptions.log file
because the create time on the file was from yesterday. At the bottom
of the email is a copy of our logging configuration which we wire up
during Application_Start.
We thought it might have originally been related to permissions as
someone had deleted the exception.log and recreated it and it was
owned by them but we fixed that last night and we had another crash
this morning. I am stumped since no code has changed on this box and
nothing unusual about the type of activity. Maybe something in a .NET
patch changed behavior?
Any assistance would be appreciated.
Thanks
Jim
Thread that appears to be blocking everything
Entry point *clr!Thread::intermediateThreadProc*
Create time *5/19/2017 1:05:32 PM*
Time spent in user mode *0 Days 00:10:06.359*
Time spent in kernel mode *0 Days 00:02:51.203*
This thread is trying to acquire a System.Threading.ReaderWriterLock
for *reading*
*The thread has evidence of _.net exceptions_ on the stack. Check the
Previous .NET Exceptions Report (Exceptions in all .NET Thread
Stacks) to view more details of the associated exception *
*.NET Call Stack*
[[HelperMethodFrame_1OBJ] (System.Array.Copy)]
System.Array.Copy(System.Array, Int32, System.Array, Int32, Int32,
Boolean)
mscorlib_ni!System.Array.Copy(System.Array, System.Array, Int32)+3e
mscorlib_ni!System.Security.Permissions.FileIOPermission.AddPathList(System.Security.Permissions.FileIOPermissionAccess,
System.Security.AccessControl.AccessControlActions, System.String[],
Boolean, Boolean, Boolean)+5a
mscorlib_ni!System.Security.Permissions.FileIOPermission..ctor(System.Security.Permissions.FileIOPermissionAccess,
System.String[], Boolean, Boolean)+2a
mscorlib_ni!System.IO.Path.GetFullPath(System.String)+5c
mscorlib_ni!System.IO.Path.GetDirectoryName(System.String)+a2
log4net.Appender.RollingFileAppender.CombinePath(System.String,
System.String)+38
log4net.Appender.RollingFileAppender.RollOverTime(Boolean)+16c
log4net.Appender.RollingFileAppender.AdjustFileBeforeAppend()+d3
log4net.Appender.RollingFileAppender.Append(log4net.Core.LoggingEvent)+13
log4net.Appender.AppenderSkeleton.DoAppend(log4net.Core.LoggingEvent)+f0
log4net.Util.AppenderAttachedImpl.AppendLoopOnAppenders(log4net.Core.LoggingEvent)+a0
log4net.Repository.Hierarchy.Logger.CallAppenders(log4net.Core.LoggingEvent)+82
log4net.Repository.Hierarchy.Logger.ForcedLog(System.Type,
log4net.Core.Level, System.Object, System.Exception)+4a
log4net.Repository.Hierarchy.Logger.Log(System.Type,
log4net.Core.Level, System.Object, System.Exception)+64
log4net.Core.LogImpl.ErrorFormat(System.String, System.Object[])+6a
Example thread blocked
Thread 36 - System ID 7332
Entry point *clr!Thread::intermediateThreadProc*
Create time *5/19/2017 1:07:12 PM*
Time spent in user mode *0 Days 00:00:00.421*
Time spent in kernel mode *0 Days 00:00:00.109*
This thread is waiting to enter a .NET Lock
*The thread has evidence of _.net exceptions_ on the stack. Check the
Previous .NET Exceptions Report (Exceptions in all .NET Thread
Stacks) to view more details of the associated exception *
*.NET Call Stack*
[[GCFrame]]
[[HelperMethodFrame_1OBJ] (System.Threading.Monitor.Enter)]
System.Threading.Monitor.Enter(System.Object)
log4net.Appender.AppenderSkeleton.DoAppend(log4net.Core.LoggingEvent)+2b
log4net.Util.AppenderAttachedImpl.AppendLoopOnAppenders(log4net.Core.LoggingEvent)+a0
log4net.Repository.Hierarchy.Logger.CallAppenders(log4net.Core.LoggingEvent)+82
log4net.Repository.Hierarchy.Logger.ForcedLog(System.Type,
log4net.Core.Level, System.Object, System.Exception)+4a
log4net.Repository.Hierarchy.Logger.Log(System.Type,
log4net.Core.Level, System.Object, System.Exception)+64
log4net.Core.LogImpl.InfoFormat(System.String, System.Object[])+6a
Configuration file
<?xml version="1.0" encoding="utf-8" ?>
<log4net>
<appender name="WebsiteLogger"
type="log4net.Appender.RollingFileAppender">
<param name="File" value="C:\logs\WebLogging.log" />
<param name="AppendToFile" value="true" />
<param name="RollingStyle" value="Composite" />
<param name="MaximumFileSize" value="10MB" />
<param name="CountDirection" value="0" />
<param name="StaticLogFileName" value="true" />
<param name="PreserveLogFileNameExtension" value="true" />
<param name="DatePattern" value=".yyyy-MM-dd" />
<param name="MaxSizeRollBackups" value="40" />
<layout type="log4net.Layout.PatternLayout">
<param name="Header" value="Date Time Level
ThreadId Class RemoteIP SessionId Message " />
<param name="Footer" value="Ending Program " />
<param name="ConversionPattern" value="%d %-5p
%-30logger{1} %-17property{ip} %-12property{sid} %m%n%exception" />
</layout>
</appender>
<appender name="ExceptionLogger"
type="log4net.Appender.RollingFileAppender">
<param name="File" value="C:\logs\Exceptions.log" />
<param name="AppendToFile" value="true" />
<param name="RollingStyle" value="Composite" />
<param name="MaximumFileSize" value="10MB" />
<param name="CountDirection" value="0" />
<param name="StaticLogFileName" value="true" />
<param name="PreserveLogFileNameExtension" value="true" />
<param name="DatePattern" value=".yyyy-MM-dd" />
<param name="MaxSizeRollBackups" value="40" />
<!-- <lockingModel
type="log4net.Appender.FileAppender+MinimalLock" /> -->
<layout type="log4net.Layout.PatternLayout">
<param name="Header" value="Date Time Level
ThreadId Class RemoteIP SessionId Message " />
<param name="Footer" value="Ending Program " />
<param name="ConversionPattern" value="%d %-5p %-30c
%-17property{ip} %-12property{sid} %m%n%exception" />
</layout>
<filter type="log4net.Filter.LevelRangeFilter">
<param name="LevelMin" value="Error" />
</filter>
</appender>
<appender name="UsageWriter"
type="log4net.Appender.RollingFileAppender">
<param name="File" value="C:\logs\Usage.csv" />
<param name="AppendToFile" value="true" />
<param name="RollingStyle" value="Composite" />
<param name="MaximumFileSize" value="10MB" />
<param name="CountDirection" value="0" />
<param name="StaticLogFileName" value="true" />
<param name="PreserveLogFileNameExtension" value="true" />
<param name="DatePattern" value=".yyyy-MM-dd" />
<param name="MaxSizeRollBackups" value="40" />
<layout type="log4net.Layout.PatternLayout">
<param name="ConversionPattern" value="%d{yyyy-MM-dd
HH:mm:ss.fff},%property{ip},%property{sid},%m%n" />
<param name="Header"
value="Date,IPAddress,SessionId,Username,MethodName,ExecutionTime,Extra "
/>
</layout>
<filter type="log4net.Filter.LoggerMatchFilter">
<param name="LoggerToMatch"
value="AccountManagementWebservice.UsageWriter" />
<param name="AcceptOnMatch" value="true" />
</filter>
<filter type="log4net.Filter.DenyAllFilter" />
</appender>
<appender name="AdoNetAppender"
type="log4net.Appender.AdoNetAppender">
<bufferSize value="1" />
<useTransactions value="false" />
<connectionType value="System.Data.SqlClient.SqlConnection,
System.Data, Version=1.0.3300.0, Culture=neutral,
PublicKeyToken=b77a5c561934e089" />
<connectionString value="data source=server;initial
catalog=db;Enlist=false;User ID=user;Password=password" />
<commandText value="INSERT INTO Log4Net
([Date],[Host],[Application],[Thread],[Level],[Logger],[Message])
VALUES (@log_date, @host, @application, @thread, @log_level, @logger,
@message)" />
<parameter>
<parameterName value="@log_date" />
<dbType value="DateTime" />
<layout type="log4net.Layout.RawTimeStampLayout" />
</parameter>
<parameter>
<parameterName value="@host" />
<dbType value="String" />
<size value="255" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%property{host}" />
</layout>
</parameter>
<parameter>
<parameterName value="@application" />
<dbType value="String" />
<size value="255" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%property{application}" />
</layout>
</parameter>
<parameter>
<parameterName value="@thread" />
<dbType value="String" />
<size value="255" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%thread" />
</layout>
</parameter>
<parameter>
<parameterName value="@log_level" />
<dbType value="String" />
<size value="50" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%level" />
</layout>
</parameter>
<parameter>
<parameterName value="@logger" />
<dbType value="String" />
<size value="255" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%logger" />
</layout>
</parameter>
<parameter>
<parameterName value="@message" />
<dbType value="String" />
<size value="4000" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%message" />
</layout>
</parameter>
<filter type="log4net.Filter.LevelRangeFilter">
<param name="LevelMin" value="Error" />
</filter>
</appender>
<root>
<level value="DEBUG" />
<appender-ref ref="WebsiteLogger" />
<appender-ref ref="ExceptionLogger" />
<appender-ref ref="AdoNetAppender" />
<appender-ref ref="UsageWriter" />
</root>
</log4net>
