[logback-user] RollingFileAppender with SizeBasedTriggeringPolicy keeps writing to rotated file

Rolando Segura rolandosegura at gmail.com
Fri May 24 19:35:00 CEST 2013


Hi Ceki,

I reproduced the problem in a dev environment (setting the maxfilesize to
1MB), There are several instances of a NullPointerException like the one
shown below.
Enabled debug in one of the pro machines but haven't seen the error yet,
however I suspect the problem should be the same.

I believe is important to mention that we are logging very large strings
sometimes larger than 40K.

Thanks,
Rolando


5/24/13 11:01:20:636 CST] 00001e2a SystemOut     O 11:01:20,635 |-ERROR in
ch.qos.logback.core.rolling.RollingFileAppender[mop] - Appender [mop]
failed to append. java.lang.NullPoi
nterException
        at java.lang.NullPointerException
        at      at
ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy.isTriggeringEvent(SizeBasedTriggeringPolicy.java:59)
        at      at
ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:143)
        at      at
ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:103)
        at      at
ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:88)
        at      at
ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48)
        at      at
ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:280)
        at      at
ch.qos.logback.classic.Logger.callAppenders(Logger.java:267)
        at      at
ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:449)
        at      at
ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:403)
        at      at ch.qos.logback.classic.Logger.info(Logger.java:607)
        at      at
bizservices_notification.BizServicesReceiveStatusNotification20100310T231159EntityAbstractBase$JSE_10.execute(BizServicesReceiveStatusNotification20100310T231159E
ntityAbstractBase.java:129)
        at      at
com.ibm.bpe.framework.ProcessBase6.executeJavaSnippet(ProcessBase6.java:330)



On Fri, May 24, 2013 at 10:26 AM, ceki <ceki at qos.ch> wrote:

> Hi Rolando,
>
> Thank you for posting your logback.xml file. I suspect that for some
> reason logback is unable to rename some of the archives.
>
> In any case, setting the debug attribute to true in <configuration>
> element should provide helpful clues as to what is going on during
> file rolling. Here is the modified <configuration> element:
>
> <configuration debug="true" scan="true">
>    ...
> </configuration>
>
> Please post the status messages on this list.
>
>
> On 24.05.2013 17:53, Rolando Segura wrote:
>
>> Hi David,
>> Configuration is below. I'm also showing the sizes of the log files,
>> you'll notice that some of them have sizes much larger to what is
>> specified with the MaxFileSize parameter of the triggering policy.
>>
>> Thanks,
>> Rolando
>>
>>
>> $ ls -l /opt/log/mop.log*
>> -rw-r--r--    1 wps wps   13366643 May 24 09:47 /opt/log/mop.log
>> -rw-r--r--    1 wps wps   67121376 May 24 09:16 /opt/log/mop.log.1
>> -rw-r--r--    1 wps wps  849229334 May 24 09:47 /opt/log/mop.log.10
>> -rw-r--r--    1 wps wps   67116193 May 23 23:16 /opt/log/mop.log.2
>> -rw-r--r--    1 wps wps   67114690 May 23 19:54 /opt/log/mop.log.3
>> -rw-r--r--    1 wps wps   31160111 May 24 09:47 /opt/log/mop.log.4
>> -rw-r--r--    1 wps wps   67110076 May 23 17:09 /opt/log/mop.log.5
>> -rw-r--r--    1 wps wps   67115644 May 23 11:38 /opt/log/mop.log.6
>> -rw-r--r--    1 wps wps   67121760 May 23 00:31 /opt/log/mop.log.7
>> -rw-r--r--    1 wps wps   29536505 May 23 17:09 /opt/log/mop.log.8
>> -rw-r--r--    1 wps wps 2053363264 May 24 09:47 /opt/log/mop.log.9
>>
>> $ ls -l /opt/log/mop.nocr*
>> -rw-r--r--    1 wps wps   25664997 May 24 09:47 /opt/log/mop.nocrlf.log
>> -rw-r--r--    1 wps wps  991283661 May 24 09:47 /opt/log/mop.nocrlf.log.1
>>
>>
>>
>> $ cat logback.xml
>> <?xml version="1.0" encoding="UTF-8"?>
>>
>> <!-- For assistance related to logback-translator or configuration  -->
>> <!-- files in general, please contact the logback user mailing list -->
>> <!-- at http://www.qos.ch/mailman/**listinfo/logback-user<http://www.qos.ch/mailman/listinfo/logback-user>            -->
>> <!--                                                                -->
>> <!-- For professional support please see                            -->
>> <!-- http://www.qos.ch/shop/**products/professionalSupport<http://www.qos.ch/shop/products/professionalSupport>        -->
>> <!--                                                                -->
>> <configuration scan="true">
>>    <appender name="SYSLOG"
>> class="ch.qos.logback.classic.**net.SyslogAppender">
>>      <syslogHost>localhost</**syslogHost>
>>      <facility>LOCAL7</facility>
>>      <suffixPattern>%d{ISO8601} %5p [%t] \(%logger\) -
>> %replace(%m){'\n',''}</**suffixPattern>
>>    </appender>
>>    <appender name="mop"
>> class="ch.qos.logback.core.**rolling.RollingFileAppender">
>>      <!--See also
>> http://logback.qos.ch/manual/**appenders.html#**RollingFileAppender--<http://logback.qos.ch/manual/appenders.html#RollingFileAppender-->
>> >
>>      <File>/opt/log/mop.log</File>
>>      <encoder>
>>        <pattern>%d{ISO8601} %5p [%t] \(%logger\) - %m%n</pattern>
>>      </encoder>
>>      <rollingPolicy
>> class="ch.qos.logback.core.**rolling.**FixedWindowRollingPolicy">
>>        <maxIndex>10</maxIndex>
>>        <FileNamePattern>/opt/log/mop.**log.%i</FileNamePattern>
>>      </rollingPolicy>
>>      <triggeringPolicy
>> class="ch.qos.logback.core.**rolling.**SizeBasedTriggeringPolicy">
>>        <MaxFileSize>64MB</**MaxFileSize>
>>      </triggeringPolicy>
>>    </appender>
>>    <appender name="mopnocrlf"
>> class="ch.qos.logback.core.**rolling.RollingFileAppender">
>>      <File>/opt/log/mop.nocrlf.log<**/File>
>>      <encoder>
>>        <pattern>[%d{ISO8601}] %5p [%t] \(%logger\) -
>> %replace(%m){'\r?\n',''}%n</**pattern>
>>      </encoder>
>>      <rollingPolicy
>> class="ch.qos.logback.core.**rolling.**FixedWindowRollingPolicy">
>>        <maxIndex>1</maxIndex>
>>        <FileNamePattern>/opt/log/mop.**nocrlf.log.%i</**FileNamePattern>
>>      </rollingPolicy>
>>      <triggeringPolicy
>> class="ch.qos.logback.core.**rolling.**SizeBasedTriggeringPolicy">
>>        <MaxFileSize>32MB</**MaxFileSize>
>>      </triggeringPolicy>
>>    </appender>
>>    <appender name="stdout" class="ch.qos.logback.core.**ConsoleAppender">
>>      <encoder>
>>        <pattern>%5p [%t] \(%logger\) - %m%n</pattern>
>>      </encoder>
>>    </appender>
>>    <logger name="mop" level="debug">
>>      <appender-ref ref="mop"/>
>>      <appender-ref ref="mopnocrlf"/>
>>    </logger>
>>    <root level="fatal">
>>      <appender-ref ref="stdout"/>
>>    </root>
>> </configuration>
>>
>>
>>
>> On Fri, May 24, 2013 at 7:21 AM, David Roussel
>> <nabble at diroussel.xsmail.com <mailto:nabble at diroussel.**xsmail.com<nabble at diroussel.xsmail.com>>>
>> wrote:
>>
>>     Roland,
>>
>>     That sounds strange. Can you post your logback.xml file?
>>
>>     David
>>
>>     On 23 May 2013, at 00:03, Rolando Segura <rolandosegura at gmail.com
>>     <mailto:rolandosegura at gmail.**com <rolandosegura at gmail.com>>> wrote:
>>
>>      >  Hi I have an RollingFileAppender with a triggering policy of
>>     rotating by size when the log reaches 32MB and a maxIndex of 1,
>>     configuration below.
>>      > It happens that after rotation logback keeps writing to both
>>     files. Is this expected? My understanding from documentation is that
>>     it will stop writing to the current log, rename it and starts
>>     writing a to a new file with the name of the File parameter.
>>      >
>>      > I'd appreciate your clarification if I'm not understanding well
>>     the RollingFileAppender and SizeBasedTriggering behavior.
>>      >
>>      > Thanks,
>>      > Rolando
>>      >
>>      >
>>      >
>>      > <appender name="lognocrlf"
>>     class="ch.qos.logback.core.**rolling.RollingFileAppender">
>>      >     <File>/opt/log/file.nocrlf.**log</File>
>>      >     <encoder>
>>      >       <pattern>[%d{ISO8601}] %5p [%t] \(%logger\) -
>>     %replace(%m){'\r?\n',''}%n</**pattern>
>>      >     </encoder>
>>      >     <rollingPolicy
>>     class="ch.qos.logback.core.**rolling.**FixedWindowRollingPolicy">
>>      >       <maxIndex>1</maxIndex>
>>      >       <FileNamePattern>/opt/log/**file.nocrlf.log.%i</**
>> FileNamePattern>
>>      >     </rollingPolicy>
>>      >     <triggeringPolicy
>>     class="ch.qos.logback.core.**rolling.**SizeBasedTriggeringPolicy">
>>      >       <MaxFileSize>32MB</**MaxFileSize>
>>      >     </triggeringPolicy>
>>      >   </appender>
>>      >
>>
>
>
>
> --
> Ceki
> 65% of statistics are made up on the spot
>
> ______________________________**_________________
> Logback-user mailing list
> Logback-user at qos.ch
> http://mailman.qos.ch/mailman/**listinfo/logback-user<http://mailman.qos.ch/mailman/listinfo/logback-user>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.qos.ch/pipermail/logback-user/attachments/20130524/1a150474/attachment.html>


More information about the Logback-user mailing list