logging-log4net-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Jim Scott" <jsc...@infoconex.com>
Subject IIS Deadlocks happening all the sudden after years of running with no issues
Date Fri, 19 May 2017 22:45:50 GMT
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&#13;&#10;" />
                  <param name="Footer" value="Ending Program&#13;&#10;" />
                  <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&#13;&#10;" />
                  <param name="Footer" value="Ending Program&#13;&#10;" />
                  <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&#13;&#10;"
/>
              </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> 

Mime
View raw message