log4net 1.2.12, rolling file appender quits logging after some time

[Douglas Neary <dn...@miteksystems.com>]

All:

First time poster, long time user.   Thanks for a great tool.

The background:
I have log4net version 1.2.12 of log4net running on Windows Server 2008 R2.  This is an Asp.net application (.Net 3.5.1) with 3 separate web sites logging to 3 separate log files using the rolling file appender.    Log4net internal logging enabled for all 3 sites and directed to separate files.  I can post that output, but I did not as it is very verbose.

I was having a similar problem with log4net 1.2.10, I just updated to 1.2.12.

The good news:
Logging works fine for all 3 sites, for a while.

The problem:
2 of the 3 logs quit writing after a while (hours, maybe a day or so max).  In the log4net internal logs, I see the following text written over and over (looks to be every time logging is attempted)
log4net: Opening file for writing [c:\logs\logfile2.log] append [False] or
log4net: Opening file for writing [c:\logs\logfile3.log] append [False]
The questions:
Can I get a timestamp emitted (or any other formatting) with log4net internal debugging?
Any idea how to track down root cause on why these 2 loggers quit logging after a while?

The web.config:
Snip of log4net from web.config from 1 site below.  The other 2 sites are identical except for the log file name.

  <log4net>
    <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
      <layout type="log4net.Layout.PatternLayout">
        <param name="ConversionPattern" value="%d [%t] %-5p %c [%x] - %m%n"/>
      </layout>
    </appender>
    <appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender">
      <param name="File" value="c:\logs\logfile1.log"/>
      <param name="AppendToFile" value="true"/>
      <param name="MaxSizeRollBackups" value="10"/>
      <param name="MaximumFileSize" value="100MB"/>
      <param name="RollingStyle" value="Size"/>
      <param name="StaticLogFileName" value="true"/>
      <layout type="log4net.Layout.PatternLayout">
        <!-- do not alter ConversionPattern, it is used for reporting.-->
        <param name="ConversionPattern" value="%date{yyyy-MM-dd HH:mm:ss.fff} [%t] [%x] %p %c - %m%n"/>
      </layout>
    </appender>
    <root>
      <level value="Info"/>
      <appender-ref ref="RollingLogFileAppender"/>
      <appender-ref ref="ConsoleAppender"/>
    </root>
  </log4net>

Thanks in advance for any guidance.

Doug

Re: log4net 1.2.12, rolling file appender quits logging after some time

[Stefan Bodewig <bo...@apache.org>]

On 2013-11-18, Douglas Neary wrote:

>>> In the past we've had reports where log4net stopped logging when IIS decided to recycle the appdomain the app was running in.  Could that be the case for here?

> No, the recycling is turned off for all 3 sites.

Then you seem to be facing we haven't been told of before.

> My feeling is posting the log4net internal logs might be helpful.  But
> they are pretty big.  Any preference as to how I should do this?  I
> could paste the log entries into separate emails if this is not
> considered bad form.

Please open a JIRA ticket and attach the logfiles.  I think there some
limit on attachment size but I'd hope the logs won't be even bigger than
that.

https://issues.apache.org/jira/browse/LOG4NET

Many thanks

     Stefan

RE: log4net 1.2.12, rolling file appender quits logging after some time

[Douglas Neary <dn...@miteksystems.com>]

Stefan:

Thanks for the reply.

>> In the past we've had reports where log4net stopped logging when IIS decided to recycle the appdomain the app was running in.  Could that be the case for here?

No, the recycling is turned off for all 3 sites.

My feeling is posting the log4net internal logs might be helpful.  But they are pretty big.  Any preference as to how I should do this?  I could paste the log entries into separate emails if this is not considered bad form.

Thanks,
Doug

-----Original Message-----
From: Stefan Bodewig [mailto:bodewig@apache.org] 
Sent: Friday, November 15, 2013 12:17 AM
To: Log4NET User
Subject: Re: log4net 1.2.12, rolling file appender quits logging after some time

On 2013-11-13, Douglas Neary wrote:

> The problem:
> 2 of the 3 logs quit writing after a while (hours, maybe a day or so 
> max).

In the past we've had reports where log4net stopped logging when IIS decided to recycle the appdomain the app was running in.  Could that be the case for here?

In those other cases the issue seemed to be with the way people initialize the logging system (so it was properly set up on application start but not when recycled), but this doesn't seem to be the case

>  In the log4net internal logs, I see the following text written over 
> and over (looks to be every time logging is attempted)
> log4net: Opening file for writing [c:\logs\logfile2.log] append 
> [False] or
> log4net: Opening file for writing [c:\logs\logfile3.log] append 
> [False]

> The questions:
> Can I get a timestamp emitted (or any other formatting) with log4net internal debugging?
> Any idea how to track down root cause on why these 2 loggers quit logging after a while?

what you see is the result of log4net.Util.LogLog.EmitOutline, which only logs the message itself.

You can attach a LogReceivedEventHandler to LogLog's LogReceived event and grab a timestamp from the LogLog instance passed in via args.
Inconvenient, no question.

Stefan

Re: log4net 1.2.12, rolling file appender quits logging after some time

[Stefan Bodewig <bo...@apache.org>]

On 2013-11-13, Douglas Neary wrote:

> The problem:
> 2 of the 3 logs quit writing after a while (hours, maybe a day or so
> max).

In the past we've had reports where log4net stopped logging when IIS
decided to recycle the appdomain the app was running in.  Could that be
the case for here?

In those other cases the issue seemed to be with the way people
initialize the logging system (so it was properly set up on application
start but not when recycled), but this doesn't seem to be the case

>  In the log4net internal logs, I see the following text written over and over (looks to be every time logging is attempted)
> log4net: Opening file for writing [c:\logs\logfile2.log] append [False] or
> log4net: Opening file for writing [c:\logs\logfile3.log] append [False]

> The questions:
> Can I get a timestamp emitted (or any other formatting) with log4net internal debugging?
> Any idea how to track down root cause on why these 2 loggers quit logging after a while?

what you see is the result of log4net.Util.LogLog.EmitOutline, which
only logs the message itself.

You can attach a LogReceivedEventHandler to LogLog's LogReceived event
and grab a timestamp from the LogLog instance passed in via args.
Inconvenient, no question.

Stefan