[logback-user] RollingFileAppender with SizeBasedTriggeringPolicy keeps writing to rotated file
Rolando Segura
rolandosegura at gmail.com
Sat May 25 01:17:28 CEST 2013
Hi David,
I'm using 1.0.11. Browsing the git repository it seems that the exception
is thrown in this line of SizeBasedTriggeringPolicy
return (activeFile.length() >= maxFileSize.getSize());
So either activeFile or maxFileSize is null; I'll download a source version
of logback and instrument it a bit more. I'll report back here of what I
find.
Thanks,
Rolando
On Fri, May 24, 2013 at 1:17 PM, David Roussel
<nabble at diroussel.xsmail.com>wrote:
> Roland,
>
> What version of logback are you using?
>
> Can you debug and find what is causing the null pointer exception?
>
> David
>
> On 24 May 2013, at 19:35, Rolando Segura <rolandosegura at gmail.com> wrote:
>
> 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>
>>
>
> _______________________________________________
> Logback-user mailing list
> Logback-user at qos.ch
> http://mailman.qos.ch/mailman/listinfo/logback-user
>
>
> _______________________________________________
> Logback-user mailing list
> Logback-user at qos.ch
> 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/0b9ad352/attachment.html>
More information about the Logback-user
mailing list